[Freeswitch-users] Possible registration/presence bug - Sometimes get "Originate Failed. Cause: USER_NOT_REGISTERED" when extension registration is present

Alex Crow acrow at integrafin.co.uk
Tue Apr 3 00:24:36 MSD 2012


Hi,

I pulled from git today and am seeing something similar, will try to get 
a trace and submit a JIRA bug. It was not happening before my pull (last 
version was pulled in the middle of Feb).

I have two profiles for extensions (internal and nat) and it seems to 
occur most often when trying to call from internal to nat registered 
devices.

Cheers

Alex

On 02/04/12 20:44, Phil Quesinberry wrote:
>
> The phone never stops working.  The problem is either present from the 
> time FS is started or it isn't.  I'll have tobring it down andtry to 
> get it to fail againafter hours so I can provide more detailed info. 
> To me, it appears from the log I capturedthat presence_id is 
> notalwaysbeing initialized properlywhen FS is startedbut I haven't 
> looked at the source code to see what's really happening.  I do have 
> the two FS books on the way though, which should give me a deeper 
> understanding of how things work.  The wiki only goes so far.
>
> Also, when I do a sofia status profile internal reg, I see a bunch 
> oflong expiredregistration entries.  Not sure if that couldsomehowbe 
> related to this problem.
>
> freeswitch at internal> sofia status profile internal reg
>
> Registrations:
>
> =================================================================================================
>
> Call-ID:        49e008f79bd41460
>
> User:           102 at 192.168.1.6
>
> Contact:        "Phil" <sip:102 at 192.168.1.4:5060;transport=udp>
>
> Agent:          Aastra 9480i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:39:06) 
> EXPSECS(271)
>
> Host:           Server
>
> IP:             192.168.1.4
>
> Port:           5060
>
> Auth-User:      102
>
> Auth-Realm:     192.168.1.6
>
> MWI-Account:    102 at 192.168.1.6
>
> Call-ID:        5f92c72e93a50f67
>
> User:           226 at 192.168.1.6
>
> Contact:        "Sonny" <sip:226 at 74.93.xx.xx:5060;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-02 13:49:47) 
> EXPSECS(-2681088)
>
> Host:           Server
>
> IP: 74.93.xx.xx
>
> Port:           1066
>
> Auth-User:      226
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    226 at 192.168.1.6
>
> Call-ID:        09856e1e62e97740
>
> User:           227 at 192.168.1.6
>
> Contact:        "Laura" <sip:227 at 74.93.xx.xx:1064;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-02 13:47:39) 
> EXPSECS(-2681216)
>
> Host:           Server
>
> IP: 74.93.xx.xx
>
> Port:           5060
>
> Auth-User:      227
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    227 at 192.168.1.6
>
> Call-ID:        69748b87cb4b8d1d
>
> User:           257 at 192.168.1.6
>
> Contact:        "Tina" <sip:257 at 74.93.xx.xx:1060;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-02 13:49:11) 
> EXPSECS(-2681124)
>
> Host:           Server
>
> IP: 74.93.xx.xx
>
> Port:           1064
>
> Auth-User:      257
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    257 at 192.168.1.6
>
> Call-ID:        45249b30-85ddd13a at 10.0.0.159
>
> User:           519 at 192.168.1.6
>
> Contact:        Fax Machine <sip:519 at 74.93.xx.xx:1062>
>
> Agent:          Linksys/SPA2102-5.2.12
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:36:47) 
> EXPSECS(132)
>
> Host:           Server
>
> IP: 74.93.xx.xx
>
> Port:           1062
>
> Auth-User:      519
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    519 at 192.168.1.6
>
> Call-ID:        effe7aec41953215
>
> User:           102 at 192.168.2.105
>
> Contact:        "Phil" <sip:102 at 192.168.2.104:5060;transport=udp>
>
> Agent:          Aastra 9480i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-09 00:22:38) 
> EXPSECS(-2124717)
>
> Host:           localhost.localdomain
>
> IP:             192.168.2.104
>
> Port:           5060
>
> Auth-User:      102
>
> Auth-Realm:     192.168.2.105
>
> MWI-Account:    102 at 192.168.2.105
>
> Call-ID:        e9351a6c40675c86
>
> User:           102 at 192.168.2.6
>
> Contact:        "Phil" <sip:102 at 192.168.2.104:5060;transport=udp>
>
> Agent:          Aastra 9480i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-15 00:46:48) 
> EXPSECS(-1608467)
>
> Host:           pbx
>
> IP:             192.168.2.104
>
> Port:           5060
>
> Auth-User:      102
>
> Auth-Realm:     192.168.2.6
>
> MWI-Account:    102 at 192.168.2.6
>
> Call-ID:        45249b30-85ddd13a at 10.0.0.159
>
> User:           519 at 192.168.2.6
>
> Contact:        Fax Machine <sip:519 at 74.93.xx.xx:1062>
>
> Agent:          Linksys/SPA2102-5.2.12
>
> Status:         Registered(UDP)(unknown) EXP(2012-03-15 00:46:23) 
> EXPSECS(-1608492)
>
> Host:           pbx
>
> IP: 74.93.xx.xx
>
> Port:           1062
>
> Auth-User:      519
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    519 at 192.168.2.6
>
> Call-ID:        864e7aef4c59c423
>
> User:           225 at 192.168.1.6
>
> Contact:        "Vicky" <sip:225 at 74.93.xx.xx:1067;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:36:25) 
> EXPSECS(110)
>
> Host:           server
>
> IP: 74.93.xx.xx
>
> Port:           1067
>
> Auth-User:      225
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    225 at 192.168.1.6
>
> Call-ID:        29b0d19d8063e55c
>
> User:           226 at 192.168.1.6
>
> Contact:        "Sonny" <sip:226 at 74.93.xx.xx:1068;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:36:25) 
> EXPSECS(110)
>
> Host:           server
>
> IP: 74.93.xx.xx
>
> Port:           1068
>
> Auth-User:      226
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    226 at 192.168.1.6
>
> Call-ID:        6bc00b660278e069
>
> User:           227 at 192.168.1.6
>
> Contact:        "Laura" <sip:227 at 74.93.xx.xx:1066;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:35:51) 
> EXPSECS(76)
>
> Host:           server
>
> IP: 74.93.xx.xx
>
> Port:           1066
>
> Auth-User:      227
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    227 at 192.168.1.6
>
> Call-ID:        e721049935e82279
>
> User:           257 at 192.168.1.6
>
> Contact:        "Tina" <sip:257 at 74.93.xx.xx:5060;transport=udp>
>
> Agent:          Aastra 9143i/3.2.2.1136
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:36:32) 
> EXPSECS(117)
>
> Host:           server
>
> IP: 74.93.xx.xx
>
> Port:           5060
>
> Auth-User:      257
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    257 at 192.168.1.6
>
> Call-ID:        54667b49ca74cabe
>
> User:           3900 at 192.168.1.6
>
> Contact:        "Brad" 
> <sip:3900 at 173.66.xx.xx:54629;transport=udp;fs_nat=yes>
>
> Agent:          Aastra 9143i/3.2.2.2044
>
> Status:         Registered(AUTO-NAT)(unknown) EXP(2012-04-02 15:36:22) 
> EXPSECS(107)
>
> Host:           server.home
>
> IP: 173.66.xx.xx
>
> Port:           54629
>
> Auth-User:      3900
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    3900 at 192.168.1.6
>
> Call-ID:        6dc54f7994ffb61a
>
> User:           3901 at 192.168.1.6
>
> Contact:        "KCC Main" 
> <sip:3901 at 173.66.xx.xx:6480;transport=udp;fs_nat=yes>
>
> Agent:          Aastra 9143i/3.2.2.2044
>
> Status:         Registered(AUTO-NAT)(unknown) EXP(2012-04-02 15:36:38) 
> EXPSECS(123)
>
> Host:           server.home
>
> IP: 173.66.xx.xx
>
> Port:           6480
>
> Auth-User:      3901
>
> Auth-Realm:     qsystemseng.ourdomain.com
>
> MWI-Account:    3901 at 192.168.1.6
>
> Call-ID:        bae1af9975ebfa50
>
> User:           2001 at 192.168.1.6
>
> Contact:        "Phil" <sip:2001 at 192.168.1.4:5060;transport=udp>
>
> Agent:          Aastra 9480i/3.2.2.2044
>
> Status:         Registered(UDP)(unknown) EXP(2012-04-02 15:36:37) 
> EXPSECS(122)
>
> Host:           server.home
>
> IP:             192.168.1.4
>
> Port:           5060
>
> Auth-User:      2001
>
> Auth-Realm:     192.168.1.6
>
> MWI-Account:    2001 at 192.168.1.6
>
> Total items returned: 15
>
> =================================================================================================
>
> - Phil
>
> ----------
>
> Anthony Minessale wrote:
>
> plus the log is not detailed enough
>
> sofia global siptrace on
>
> sofia loglevel all 9
>
> console loglevel debug (/log debug)
>
> you would need enough log to cover the time when the phone is working
>
> until when it stops working.
>
> _____________________________________________
> *From:*Phil Quesinberry [mailto:philq at qsystemsengineering.com]
> *Sent:*Monday, April 02, 2012 12:37 AM
> *To:*'freeswitch-users at lists.freeswitch.org'
> *Subject:*Possible registration/presence bug - Sometimes get 
> "Originate Failed. Cause: USER_NOT_REGISTERED" when extension 
> registration is present
>
> Hi,
>
> I've noticed what appears to be a bug which I wanted to bring to your 
> attention.  Sometimes when FS is started, extensions can't be called 
> even after they've registered.  This doesn't happen all the time... 
> and restarting FS always solves the problem.  Just to be clear - this 
> problem only sometimes occurs when FS has been started/restarted, like 
> after an update.  Once FS has "started successfully" and sees presence 
> for registered extensions, it continues to work fine.
>
> It's all or nothing -- no extensions can be dialed when this issue is 
> present, whether they're local or NATted.  If one extension can be 
> reached, you can reach them all (if they're registered, of course).
>
> See debug info below on an attempt to dial a local (no NAT) extension 
> -- this was one of the recent beta git pulls and the problem has been 
> present through several updates.  Let me know if you need any 
> additional info.
>
>
> freeswitch at internal> show registrations
>
> reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostname
>
> 102,192.168.1.6,a7289b6393a8023e,sofia/internal/sip:102 at 192.168.1.4:5060;transport=udp,1333338853,192.168.1.4,5060,udp,server.home
>
> 257,192.168.1.6,aab02ec49af03567,sofia/internal/sip:257 at 74.93.222.xx.xx:5060;transport=udp,1333338709,74.93.xx.xx,5060,udp,server.home
>
> 2001,192.168.1.6,bae1af9975ebfa50,sofia/internal/sip:2001 at 192.168.1.4:5060;transport=udp,1333338743,192.168.1.4,5060,udp,server.home
>
> 227,192.168.1.6,42db21f84f52e3ef,sofia/internal/sip:227 at 74.93.xx.xx:1066;transport=udp,1333338747,74.93.xx.xx,1066,udp,server.home
>
> 226,192.168.1.6,25619841fc53c75e,sofia/internal/sip:226 at 74.93.xx.xx:1068;transport=udp,1333338751,74.93.xx.xx,1068,udp,server.home
>
> 225,192.168.1.6,308cce2ca1734cdc,sofia/internal/sip:225 at 74.93.xx.xx:1067;transport=udp,1333338751,74.93.xx.xx,1067,udp,server.home
>
> 3900,192.168.1.6,54667b49ca74cabe,sofia/internal/sip:3900 at 173.66.xx.xx:54629;transport=udp;fs_nat=yes,1333338762,173.66.xx.xx,54629,udp,server.home
>
> 3901,192.168.1.6,6dc54f7994ffb61a,sofia/internal/sip:3901 at 173.66.xx.xx:6480;transport=udp;fs_nat=yes,1333338779,173.66.xx.xx,6480,udp,server.home
>
> 519,192.168.1.6,45249b30-85ddd13a at 10.0.0.159,sofia/internal/sip:519 at 74.93.xx.xx:1062,1333338779,74.93.xx.xx,1062,udp,server.home
>
> 9 total.
>
> 2012-04-01 23:50:41.449612 [DEBUG] sofia.c:7576 IP 192.168.1.4 
> Rejected by acl "domains". Falling back to Digest auth.
>
> 2012-04-01 23:50:41.449612 [WARNING] sofia_reg.c:1422 SIP auth 
> challenge (INVITE) on sofia profile 'internal' for [2001 at 192.168.1.6] 
> from ip 192.168.1.4
>
> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:7576 IP 192.168.1.4 
> Rejected by acl "domains". Falling back to Digest auth.
>
> 2012-04-01 23:50:41.549553 [NOTICE] switch_channel.c:926 New Channel 
> sofia/internal/102 at 192.168.1.6:5060 [9a9a3bde-116c-4100-b269-a6be7455c6c1]
>
> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5541 Channel 
> sofia/internal/102 at 192.168.1.6:5060 entering state [received][100]
>
> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5552 Remote SDP:
>
> v=0
>
> o=MxSIP 0 1 IN IP4 192.168.1.4
>
> s=SIP Call
>
> c=IN IP4 192.168.1.4
>
> t=0 0
>
> m=audio 16384 RTP/AVP 0 110 8 9
>
> a=rtpmap:0 PCMU/8000
>
> a=rtpmap:110 PCMU/16000
>
> a=rtpmap:8 PCMA/8000
>
> a=rtpmap:9 G722/8000
>
> a=silenceSupp:off - - - -
>
> a=ptime:20
>
> 2012-04-01 23:50:41.549553 [DEBUG] sofia.c:5746 
> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_NEW -> CS_INIT
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_INIT
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401 
> (sofia/internal/102 at 192.168.1.6:5060) State INIT
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:85 
> sofia/internal/102 at 192.168.1.6:5060 SOFIA INIT
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:125 
> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_INIT -> CS_ROUTING
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:401 
> (sofia/internal/102 at 192.168.1.6:5060) State INIT going to sleep
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_ROUTING
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1886 
> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change DOWN -> RINGING
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410 
> (sofia/internal/102 at 192.168.1.6:5060) State ROUTING
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:148 
> sofia/internal/102 at 192.168.1.6:5060 SOFIA ROUTING
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:104 
> sofia/internal/102 at 192.168.1.6:5060 Standard ROUTING
>
> 2012-04-01 23:50:41.549553 [INFO] mod_dialplan_xml.c:485 Processing 
> Phil <102>->2001 in context default
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->unloop] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unloop] 
> ${unroll_loops}(true) =~ /^true$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unloop] 
> ${sip_looped_call}() =~ /^true$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->call_direction] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [call_direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 ANTI-Action 
> set(call_direction=local)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->tod_example] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Date/TimeMatch (FAIL) 
> [tod_example] break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->holiday_example] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Date/TimeMatch (FAIL) 
> [holiday_example] break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->group-intercept] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->redial] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [redial] 
> destination_number(2001) =~ /^(redial|\*870)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->global] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [global] 
> ${call_debug}(false) =~ /^true$/ break=never
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [global] 
> ${sip_has_crypto}() =~ 
> /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Absolute Condition [global]
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-last_dial/global/${uuid})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->snom-demo-2] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [snom-demo-2] destination_number(2001) =~ /^\*9001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->snom-demo-1] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [snom-demo-1] destination_number(2001) =~ /^\*9000$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->call_privacy] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [call_privacy] destination_number(2001) =~ /^\*67(\d+)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->call_return] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [call_return] destination_number(2001) =~ /^\*69$|^869$|^lcr$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->del-group] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [del-group] 
> destination_number(2001) =~ /^\*\*80(\d{2})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->add-group] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [add-group] 
> destination_number(2001) =~ /^\*\*81(\d{2})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->call-group-simo] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [call-group-simo] destination_number(2001) =~ /^\*\*82(\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->call-group-order] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [call-group-order] destination_number(2001) =~ /^\*83(\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->intercept-ext] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [intercept-ext] destination_number(2001) =~ /^\*\*(\d+)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Local_Extension_Skinny] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [Local_Extension_Skinny] destination_number(2001) =~ /^(11[01][0-9])$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->send_to_voicemail] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,7})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->enum.9.10d] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [enum.9.10d] destination_number(2001) =~ /^9(\d{10})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->enum.9.11d] continue=true
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [enum.9.11d] destination_number(2001) =~ /^9(\d{11})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->SipBroker.SIPDial] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [SipBroker.SIPDial] destination_number(2001) =~ /^([*]\d{5,})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->SipBroker.Toll_Free] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [SipBroker.Toll_Free] destination_number(2001) =~ 
> /^91?(8(00|66|77|88)[2-9]\d{6})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->TollFreeGateway] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [TollFreeGateway] destination_number(2001) =~ 
> /^91?(8(00|55|66|77|88)[2-9]\d{6})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->FlowRoute.91d10or11] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [FlowRoute.91d10or11] destination_number(2001) =~ /^91?(\d{10})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->HL7519.9.10d] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [HL7519.9.10d] caller_id_number(102) =~ /519/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->HL7519.9.11d] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [HL7519.9.11d] caller_id_number(102) =~ /519/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->HL7612.9.10d] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) 
> [HL7612.9.10d] ${toll_allow}(local,domestic) =~ /local/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [HL7612.9.10d] destination_number(2001) =~ /^9(\d{10})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->HL7612.9.11d] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) 
> [HL7612.9.11d] ${toll_allow}(local,domestic) =~ /local/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [HL7612.9.11d] destination_number(2001) =~ /^9(\d{11})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->enum.7d7] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [enum.7d7] 
> destination_number(2001) =~ /^7(\d{7})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->xmpp.8d10] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [xmpp.8d10] 
> destination_number(2001) =~ /^8(\d{10})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->xmpp.8d11] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [xmpp.8d11] 
> destination_number(2001) =~ /^8(\d{11})$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Talking Clock Time] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking 
> Clock Time] destination_number(2001) =~ /^9170$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Talking Clock Date] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking 
> Clock Date] destination_number(2001) =~ /^9171$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Talking Clock Date and Time] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Talking 
> Clock Date and Time] destination_number(2001) =~ /^9172$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Recordings] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [Recordings] destination_number(2001) =~ /^\*(732)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Company_Directory] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [Company_Directory] destination_number(2001) =~ /^5001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Hersch_Lauren_Main] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [Hersch_Lauren_Main] destination_number(2001) =~ /^5000$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Holiday_Announcement] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [Holiday_Announcement] destination_number(2001) =~ /^5010$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Ring 
> all admin phones.park] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Ring all 
> admin phones.park] destination_number(2001) =~ /^\*1001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->Ring 
> all admin phones] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [Ring all 
> admin phones] destination_number(2001) =~ /^1001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->group_dial_sales] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [group_dial_sales] destination_number(2001) =~ /^\*2000$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->group_dial_support] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [group_dial_support] destination_number(2001) =~ /^\*2001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->group_dial_billing] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [group_dial_billing] destination_number(2001) =~ /^\*2002$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->operator] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [operator] 
> destination_number(2001) =~ /^operator$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->vmain] 
> continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain] 
> destination_number(2001) =~ /^vmain$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->vmain1] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain1] 
> destination_number(2001) =~ /^vmain1$|^\*97$|^\*4000$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->vmain2] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [vmain2] 
> destination_number(2001) =~ /^vmain2$|^\*98$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->sip_uri] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [sip_uri] 
> destination_number(2001) =~ /^sip:(.*)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->nb_conferences] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [nb_conferences] destination_number(2001) =~ /^\*(30\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->wb_conferences] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [wb_conferences] destination_number(2001) =~ /^\*(31\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->uwb_conferences] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [uwb_conferences] destination_number(2001) =~ /^\*(32\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->cdquality_conferences] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [cdquality_conferences] destination_number(2001) =~ /^\*(33\d{2})$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->freeswitch_public_conf_via_sip] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [freeswitch_public_conf_via_sip] destination_number(2001) =~ 
> /^\*9(888|8888|1616|3232)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ivr_demo] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [ivr_demo] 
> destination_number(2001) =~ /^\*5000$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->dynamic_conference] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [dynamic_conference] destination_number(2001) =~ /^\*5001$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->rtp_multicast_page] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [rtp_multicast_page] destination_number(2001) =~ 
> /^pagegroup$|^\*7243$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->parking_slots] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [parking_slots] destination_number(2001) =~ /^(\*59[0-9][0-9])$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->valet_park_in] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [valet_park_in] destination_number(2001) =~ /^\*(6000)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->valet_park_out] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [valet_park_out] destination_number(2001) =~ /^\*(60\d\d)$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->park] 
> continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [park] 
> source(mod_sofia) =~ /mod_sofia/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [park] 
> destination_number(2001) =~ /park\+(\d+)/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->unpark] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unpark] 
> source(mod_sofia) =~ /mod_sofia/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unpark] 
> destination_number(2001) =~ /^parking$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->park] 
> continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [park] 
> source(mod_sofia) =~ /mod_sofia/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [park] 
> destination_number(2001) =~ /callpark/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->unpark] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) [unpark] 
> source(mod_sofia) =~ /mod_sofia/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [unpark] 
> destination_number(2001) =~ /pickup/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->wait] 
> continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [wait] 
> destination_number(2001) =~ /^wait$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->fax_receive] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [fax_receive] destination_number(2001) =~ /^\*9178$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->fax_transmit] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [fax_transmit] destination_number(2001) =~ /^\*9179$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ringback_180] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [ringback_180] destination_number(2001) =~ /^\*9180$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ringback_183_uk_ring] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [ringback_183_uk_ring] destination_number(2001) =~ /^\*9181$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ringback_183_music_ring] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [ringback_183_music_ring] destination_number(2001) =~ /^\*9182$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ringback_post_answer_uk_ring] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [ringback_post_answer_uk_ring] destination_number(2001) =~ /^\*9183$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ringback_post_answer_music] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [ringback_post_answer_music] destination_number(2001) =~ /^\*9184$/ 
> break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->ClueCon] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [ClueCon] 
> destination_number(2001) =~ /^\*9191$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->show_info] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [show_info] 
> destination_number(2001) =~ /^\*9192$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->video_record] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [video_record] destination_number(2001) =~ /^\*9193$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->video_playback] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [video_playback] destination_number(2001) =~ /^\*9194$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->delay_echo] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [delay_echo] destination_number(2001) =~ /^\*9195$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing [default->echo] 
> continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [echo] 
> destination_number(2001) =~ /^\*9196$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->milliwatt] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) [milliwatt] 
> destination_number(2001) =~ /^\*9197$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->tone_stream] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [tone_stream] destination_number(2001) =~ /^\*9198$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->zrtp_enrollement] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [zrtp_enrollement] destination_number(2001) =~ /^\*9787$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->hold_music] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (FAIL) 
> [hold_music] destination_number(2001) =~ /^\*9664$/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 parsing 
> [default->Local_Extension] continue=false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Regex (PASS) 
> [Local_Extension] destination_number(2001) =~ /(^\d{2,7}$)/ break=on-false
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(dialed_extension=2001)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> export(dialed_extension=2001)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action limit(db 
> ${domain_name} 2001 ${limit_max} ${limit_destination})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(1 b 
> s execute_extension::dx XML features)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(2 b 
> s 
> record_session::/usr/local/freeswitch/recordings/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.wav)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(3 b 
> s execute_extension::cf XML features)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action bind_meta_app(4 b 
> s execute_extension::att_xfer XML features)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(ringback=%(2000, 4000, 440.0, 480.0))
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(transfer_ringback=%(2000, 4000, 440.0, 480.0))
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action set(call_timeout=24)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(hangup_after_bridge=true)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(continue_on_fail=true)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} 
> var callgroup)})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action 
> bridge(user/${user_data(${destination_number}@${domain_name} attr 
> id)}@${domain_name})
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action answer()
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action sleep(1000)
>
> Dialplan: sofia/internal/102 at 192.168.1.6:5060 Action voicemail(default 
> ${domain_name} ${dialed_extension})
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:154 
> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_ROUTING -> 
> CS_EXECUTE
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:410 
> (sofia/internal/102 at 192.168.1.6:5060) State ROUTING going to sleep
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:362 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_EXECUTE
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:417 
> (sofia/internal/102 at 192.168.1.6:5060) State EXECUTE
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_sofia.c:241 
> sofia/internal/102 at 192.168.1.6:5060 SOFIA EXECUTE
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_core_state_machine.c:192 
> sofia/internal/102 at 192.168.1.6:5060 Standard EXECUTE
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(call_direction=local)
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [call_direction]=[local]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-spymap/102/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-last_dial/102/2001)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-last_dial/global/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(RFC2822_DATE=Sun, 01 
> Apr 2012 23:50:41 -0400)
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [RFC2822_DATE]=[Sun, 01 Apr 
> 2012 23:50:41 -0400]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(dialed_extension=2001)
>
> 2012-04-01 23:50:41.549553 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [dialed_extension]=[2001]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 export(dialed_extension=2001)
>
> 2012-04-01 23:50:41.549553 [DEBUG] switch_channel.c:1093 EXPORT 
> (export_vars) [dialed_extension]=[2001]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 limit(db 192.168.1.6 2001 5 )
>
> 2012-04-01 23:50:41.549553 [INFO] switch_limit.c:126 incr called: 
> 192.168.1.6_2001 max:5, interval:0
>
> 2012-04-01 23:50:41.569549 [INFO] mod_db.c:197 Usage for 
> 192.168.1.6_2001 is now 1/5
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(1 b s 
> execute_extension::dx XML features)
>
> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: 
> *1 execute_extension::dx XML features
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(2 b s 
> record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bde-116c-4100-b269-a6be7455c6c1.wav)
>
> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: 
> *2 
> record_session::/usr/local/freeswitch/recordings/archive/2012/Apr/01/9a9a3bde-116c-4100-b269-a6be7455c6c1.wav
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(3 b s 
> execute_extension::cf XML features)
>
> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: 
> *3 execute_extension::cf XML features
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bind_meta_app(4 b s 
> execute_extension::att_xfer XML features)
>
> 2012-04-01 23:50:41.569549 [INFO] switch_ivr_async.c:3204 Bound B-Leg: 
> *4 execute_extension::att_xfer XML features
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(ringback=%(2000, 4000, 
> 440.0, 480.0))
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [ringback]=[%(2000, 4000, 
> 440.0, 480.0)]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> set(transfer_ringback=%(2000, 4000, 440.0, 480.0))
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [transfer_ringback]=[%(2000, 
> 4000, 440.0, 480.0)]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(call_timeout=24)
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [call_timeout]=[24]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(hangup_after_bridge=true)
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [hangup_after_bridge]=[true]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(continue_on_fail=true)
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [continue_on_fail]=[true]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-call_return/2001/102)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-last_dial_ext/2001/9a9a3bde-116c-4100-b269-a6be7455c6c1)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 set(called_party_callgroup=)
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_dptools.c:1281 
> sofia/internal/102 at 192.168.1.6:5060 SET [called_party_callgroup]=[UNDEF]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 
> hash(insert/192.168.1.6-last_dial//9a9a3bde-116c-4100-b269-a6be7455c6c1)
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 bridge(user/2001 at 192.168.1.6)
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047 
> sofia/internal/102 at 192.168.1.6:5060 EXPORTING[export_vars] 
> [dialed_extension]=[2001] to event
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing 
> global variables
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:1047 
> sofia/internal/102 at 192.168.1.6:5060 EXPORTING[export_vars] 
> [dialed_extension]=[2001] to event
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:1884 Parsing 
> global variables
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing 
> variable [sip_invite_domain]=[192.168.1.6]
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_event.c:1522 Parsing 
> variable [presence_id]=[2001 at 192.168.1.6]
>
> 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot 
> create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 
> Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
>
> 2012-04-01 23:50:41.569549 [NOTICE] switch_ivr_originate.c:2459 Cannot 
> create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_ivr_originate.c:3364 
> Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
>
> 2012-04-01 23:50:41.569549 [INFO] mod_dptools.c:2922 Originate 
> Failed.  Cause: USER_NOT_REGISTERED
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 answer()
>
> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:4876 Audio Codec 
> Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
>
> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:2996 Set Codec 
> sofia/internal/102 at 192.168.1.6:5060 PCMU/8000 20 ms 160 samples 64000 bits
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_codec.c:111 
> sofia/internal/102 at 192.168.1.6:5060 Original read codec set to PCMU:0
>
> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:5008 No 2833 in SDP.  
> Disable 2833 dtmf and switch to INFO
>
> 2012-04-01 23:50:41.569549 [DEBUG] sofia_glue.c:3248 AUDIO RTP 
> [sofia/internal/102 at 192.168.1.6:5060] 192.168.1.6 port 23164 -> 
> 192.168.1.4 port 16384 codec: 0 ms: 20
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_rtp.c:1661 Starting timer 
> [soft] 160 bytes per 20ms
>
> 2012-04-01 23:50:41.569549 [NOTICE] sofia_glue.c:4022 Pre-Answer 
> sofia/internal/102 at 192.168.1.6:5060!
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:2932 
> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change RINGING -> EARLY
>
> 2012-04-01 23:50:41.569549 [DEBUG] mod_sofia.c:750 Local SDP 
> sofia/internal/102 at 192.168.1.6:5060:
>
> v=0
>
> o=FreeSWITCH 1333315477 1333315478 IN IP4 192.168.1.6
>
> s=FreeSWITCH
>
> c=IN IP4 192.168.1.6
>
> t=0 0
>
> m=audio 23164 RTP/AVP 0
>
> a=rtpmap:0 PCMU/8000
>
> a=silenceSupp:off - - - -
>
> a=ptime:20
>
> a=sendrecv
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:731 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_channel.c:3190 
> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change EARLY -> ACTIVE
>
> 2012-04-01 23:50:41.569549 [NOTICE] mod_dptools.c:1135 Channel 
> [sofia/internal/102 at 192.168.1.6:5060] has been answered
>
> 2012-04-01 23:50:41.569549 [DEBUG] switch_core_session.c:877 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.569549 [DEBUG] sofia.c:5541 Channel 
> sofia/internal/102 at 192.168.1.6:5060 entering state [completed][200]
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 sleep(1000)
>
> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.649589 [DEBUG] switch_core_session.c:877 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:41.669832 [DEBUG] sofia.c:5541 Channel 
> sofia/internal/102 at 192.168.1.6:5060 entering state [ready][200]
>
> 2012-04-01 23:50:41.849781 [DEBUG] switch_rtp.c:3224 Correct ip/port 
> confirmed.
>
> EXECUTE sofia/internal/102 at 192.168.1.6:5060 voicemail(default 
> 192.168.1.6 2001)
>
> 2012-04-01 23:50:42.689527 [DEBUG] switch_ivr_play_say.c:1306 Codec 
> Activated L16 at 8000hz 1 channels 20ms
>
> 2012-04-01 23:50:46.249491 [DEBUG] switch_core_session.c:877 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2848 
> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change ACTIVE -> HANGUP
>
> 2012-04-01 23:50:46.269490 [NOTICE] sofia.c:628 Hangup 
> sofia/internal/102 at 192.168.1.6:5060 [CS_EXECUTE] [NORMAL_CLEARING]
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_channel.c:2871 Send signal 
> sofia/internal/102 at 192.168.1.6:5060 [KILL]
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_ivr_play_say.c:1678 done 
> playing file 
> /usr/local/freeswitch/storage/voicemail/default/192.168.1.6/2001/greeting_1.wav
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:2287 
> sofia/internal/102 at 192.168.1.6:5060 skip receive message 
> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:417 
> (sofia/internal/102 at 192.168.1.6:5060) State EXECUTE going to sleep
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_HANGUP
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602 
> (sofia/internal/102 at 192.168.1.6:5060) State HANGUP
>
> 2012-04-01 23:50:46.269490 [DEBUG] mod_sofia.c:469 Channel 
> sofia/internal/102 at 192.168.1.6:5060 hanging up, cause: NORMAL_CLEARING
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:47 
> sofia/internal/102 at 192.168.1.6:5060 Standard HANGUP, cause: 
> NORMAL_CLEARING
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:602 
> (sofia/internal/102 at 192.168.1.6:5060) State HANGUP going to sleep
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:393 
> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_HANGUP -> 
> CS_REPORTING
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:362 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_REPORTING
>
> 2012-04-01 23:50:46.269490 [DEBUG] switch_core_state_machine.c:662 
> (sofia/internal/102 at 192.168.1.6:5060) State REPORTING
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:79 
> sofia/internal/102 at 192.168.1.6:5060 Standard REPORTING, cause: 
> NORMAL_CLEARING
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:662 
> (sofia/internal/102 at 192.168.1.6:5060) State REPORTING going to sleep
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:387 
> (sofia/internal/102 at 192.168.1.6:5060) State Change CS_REPORTING -> 
> CS_DESTROY
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1182 Send 
> signal sofia/internal/102 at 192.168.1.6:5060 [BREAK]
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_session.c:1382 Session 
> 13 (sofia/internal/102 at 192.168.1.6:5060) Locked, Waiting on external 
> entities
>
> 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1400 Session 
> 13 (sofia/internal/102 at 192.168.1.6:5060) Ended
>
> 2012-04-01 23:50:46.289510 [NOTICE] switch_core_session.c:1402 Close 
> Channel sofia/internal/102 at 192.168.1.6:5060 [CS_DESTROY]
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:491 
> (sofia/internal/102 at 192.168.1.6:5060) Callstate Change HANGUP -> DOWN
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:494 
> (sofia/internal/102 at 192.168.1.6:5060) Running State Change CS_DESTROY
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504 
> (sofia/internal/102 at 192.168.1.6:5060) State DESTROY
>
> 2012-04-01 23:50:46.289510 [DEBUG] mod_sofia.c:374 
> sofia/internal/102 at 192.168.1.6:5060 SOFIA DESTROY
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:86 
> sofia/internal/102 at 192.168.1.6:5060 Standard DESTROY
>
> 2012-04-01 23:50:46.289510 [DEBUG] switch_core_state_machine.c:504 
> (sofia/internal/102 at 192.168.1.6:5060) State DESTROY going to sleep
>
> freeswitch at internal> /bye
>
> [root at server bin]#
>
> Regards,
>
> /Phil Quesinberry/
>
> Q Systems Engineering, Inc.
>
> Electronic Controls and Embedded Systems Development
>
> (410) 969-8002
>
> _http://www.qsystemsengineering.com_
>
>
> -- 
> This message has been scanned for viruses and
> dangerous content by *MailScanner* <http://www.mailscanner.info/>, and is
> believed to be clean.
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org


-- 
This message is intended only for the addressee and may contain
confidential information.  Unless you are that person, you may not
disclose its contents or use it in any way and are requested to delete
the message along with any attachments and notify us immediately.

"Transact" is operated by Integrated Financial Arrangements plc
Domain House, 5-7 Singer Street, London  EC2A 4BQ
Tel: (020) 7608 4900 Fax: (020) 7608 5300
(Registered office: as above; Registered in England and Wales under number: 3727592)
Authorised and regulated by the Financial Services Authority (entered on the FSA Register; number: 190856)

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20120402/e67cc49b/attachment-0001.html 


Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list