[Freeswitch-users] Help needed on basic dialing plan: no calls are routed

Sun Sep 11 03:40:04 MSD 2011

hello all,

i have a freeswitch installation running and 2 phones connected to it. i setup 1 inbound rule. when i dial the external number i receive the following messages in the log. to me it seems that the routing works correctly but the  transfer to extension 77 fails.

note: further down the error messages i receive when trying to call internally.

any help appreciated.

regards, alexander

LOG EXTERNAL -> INTERNAL

2011-09-11 01:17:17.368068 [NOTICE] switch_channel.c:908 New Channel sofia/external/0476058096 at voip.belgacom.be [068a829e-dc03-11e0-81f7-f9f410ff919e]
2011-09-11 01:17:17.368068 [DEBUG] sofia.c:5156 Channel sofia/external/0476058096 at voip.belgacom.be entering state [received][100]
2011-09-11 01:17:17.368068 [DEBUG] sofia.c:5167 Remote SDP:
v=0
o=- 0 98592702 IN IP4 81.240.251.38
s=IMSS
c=IN IP4 81.240.251.38
t=0 0
m=audio 10874 RTP/AVP 8 18 0 101
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-15

2011-09-11 01:17:17.368068 [DEBUG] sofia_glue.c:4739 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2011-09-11 01:17:17.368068 [DEBUG] sofia_glue.c:2857 Set Codec sofia/external/0476058096 at voip.belgacom.be PCMA/8000 20 ms 160 samples 64000 bits
2011-09-11 01:17:17.368068 [DEBUG] sofia_glue.c:4859 Set 2833 dtmf send/recv payload to 101
2011-09-11 01:17:17.368068 [DEBUG] sofia.c:5357 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_NEW -> CS_INIT
2011-09-11 01:17:17.368068 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.368068 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_INIT
2011-09-11 01:17:17.368068 [DEBUG] switch_core_state_machine.c:375 (sofia/external/0476058096 at voip.belgacom.be) State INIT
2011-09-11 01:17:17.368068 [DEBUG] mod_sofia.c:85 sofia/external/0476058096 at voip.belgacom.be SOFIA INIT
2011-09-11 01:17:17.368068 [DEBUG] mod_sofia.c:125 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_INIT -> CS_ROUTING
2011-09-11 01:17:17.368068 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.368068 [DEBUG] switch_core_state_machine.c:375 (sofia/external/0476058096 at voip.belgacom.be) State INIT going to sleep
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_channel.c:1837 (sofia/external/0476058096 at voip.belgacom.be) Callstate Change DOWN -> RINGING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:384 (sofia/external/0476058096 at voip.belgacom.be) State ROUTING
2011-09-11 01:17:17.388551 [DEBUG] mod_sofia.c:148 sofia/external/0476058096 at voip.belgacom.be SOFIA ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:78 sofia/external/0476058096 at voip.belgacom.be Standard ROUTING
2011-09-11 01:17:17.388551 [INFO] mod_dialplan_xml.c:336 Processing 0476058096 <0476058096>->015261786 in context public
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [public->unloop] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [public->outside_call] continue=true
Dialplan: sofia/external/0476058096 at voip.belgacom.be Absolute Condition [outside_call]
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action set(outside_call=true) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [public->call_debug] continue=true
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [public->public_extensions] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [public_extensions] destination_number(015261786) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [public->015261786] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [015261786] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [015261786] destination_number(015261786) =~ /^015261786$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action transfer(77 XML default) 
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:128 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_ROUTING -> CS_EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:384 (sofia/external/0476058096 at voip.belgacom.be) State ROUTING going to sleep
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:391 (sofia/external/0476058096 at voip.belgacom.be) State EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] mod_sofia.c:241 sofia/external/0476058096 at voip.belgacom.be SOFIA EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:166 sofia/external/0476058096 at voip.belgacom.be Standard EXECUTE
EXECUTE sofia/external/0476058096 at voip.belgacom.be set(outside_call=true)
2011-09-11 01:17:17.388551 [DEBUG] mod_dptools.c:1167 sofia/external/0476058096 at voip.belgacom.be SET [outside_call]=[true]
EXECUTE sofia/external/0476058096 at voip.belgacom.be set(RFC2822_DATE=Sun, 11 Sep 2011 01:17:17 +0200)
2011-09-11 01:17:17.388551 [DEBUG] mod_dptools.c:1167 sofia/external/0476058096 at voip.belgacom.be SET [RFC2822_DATE]=[Sun, 11 Sep 2011 01:17:17 +0200]
EXECUTE sofia/external/0476058096 at voip.belgacom.be transfer(77 XML default)
2011-09-11 01:17:17.388551 [DEBUG] switch_ivr.c:1693 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_EXECUTE -> CS_ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:724 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [NOTICE] switch_ivr.c:1699 Transfer sofia/external/0476058096 at voip.belgacom.be to XML[77 at default]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:391 (sofia/external/0476058096 at voip.belgacom.be) State EXECUTE going to sleep
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:384 (sofia/external/0476058096 at voip.belgacom.be) State ROUTING
2011-09-11 01:17:17.388551 [DEBUG] mod_sofia.c:148 sofia/external/0476058096 at voip.belgacom.be SOFIA ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:78 sofia/external/0476058096 at voip.belgacom.be Standard ROUTING
2011-09-11 01:17:17.388551 [INFO] mod_dialplan_xml.c:336 Processing 0476058096 <0476058096>->77 in context default
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->unloop] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->tod_example] continue=true
Dialplan: sofia/external/0476058096 at voip.belgacom.be Date/Time Match (FAIL) [tod_example] break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->holiday_example] continue=true
Dialplan: sofia/external/0476058096 at voip.belgacom.be Date/Time Match (FAIL) [holiday_example] break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->global-intercept] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [global-intercept] destination_number(77) =~ /^886$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->group-intercept] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [group-intercept] destination_number(77) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->intercept-ext] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [intercept-ext] destination_number(77) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->redial] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [redial] destination_number(77) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->global] continue=true
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: sofia/external/0476058096 at voip.belgacom.be Absolute Condition [global]
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action hash(insert/${domain_name}-last_dial/global/${uuid}) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->snom-demo-2] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [snom-demo-2] destination_number(77) =~ /^9001$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->snom-demo-1] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [snom-demo-1] destination_number(77) =~ /^9000$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [eavesdrop] destination_number(77) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [eavesdrop] destination_number(77) =~ /^779$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->call_return] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [call_return] destination_number(77) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->del-group] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [del-group] destination_number(77) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->add-group] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [add-group] destination_number(77) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->call-group-simo] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [call-group-simo] destination_number(77) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->call-group-order] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [call-group-order] destination_number(77) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->extension-intercom] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [extension-intercom] destination_number(77) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->Local_Extension] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [Local_Extension] destination_number(77) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->Local_Extension_Skinny] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [Local_Extension_Skinny] destination_number(77) =~ /^(11[01][0-9])$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->group_dial_sales] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [group_dial_sales] destination_number(77) =~ /^2000$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->group_dial_support] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [group_dial_support] destination_number(77) =~ /^2001$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->group_dial_billing] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [group_dial_billing] destination_number(77) =~ /^2002$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->operator] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [operator] destination_number(77) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->vmain] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [vmain] destination_number(77) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->sip_uri] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [sip_uri] destination_number(77) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->nb_conferences] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [nb_conferences] destination_number(77) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->wb_conferences] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [wb_conferences] destination_number(77) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->uwb_conferences] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [uwb_conferences] destination_number(77) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [cdquality_conferences] destination_number(77) =~ /^(33\d{2})$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(77) =~ /^9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [mad_boss_intercom] destination_number(77) =~ /^0911$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [mad_boss_intercom] destination_number(77) =~ /^0912$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->mad_boss] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [mad_boss] destination_number(77) =~ /^0913$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ivr_demo] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ivr_demo] destination_number(77) =~ /^5000$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->dynamic_conference] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [dynamic_conference] destination_number(77) =~ /^5001$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->rtp_multicast_page] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [rtp_multicast_page] destination_number(77) =~ /^pagegroup$|^7243$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->park] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [park] destination_number(77) =~ /^5900$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->unpark] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [unpark] destination_number(77) =~ /^5901$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->valet_park] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [valet_park] destination_number(77) =~ /^(6000)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->valet_park] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [valet_park] destination_number(77) =~ /^(60\d[1-9])$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->park] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [park] destination_number(77) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->unpark] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [unpark] destination_number(77) =~ /^parking$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->park] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [park] destination_number(77) =~ /callpark/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->unpark] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [unpark] destination_number(77) =~ /pickup/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->wait] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [wait] destination_number(77) =~ /^wait$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->fax_receive] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [fax_receive] destination_number(77) =~ /^9178$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->fax_transmit] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [fax_transmit] destination_number(77) =~ /^9179$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ringback_180] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ringback_180] destination_number(77) =~ /^9180$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ringback_183_uk_ring] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ringback_183_uk_ring] destination_number(77) =~ /^9181$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ringback_183_music_ring] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ringback_183_music_ring] destination_number(77) =~ /^9182$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(77) =~ /^9183$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ringback_post_answer_music] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ringback_post_answer_music] destination_number(77) =~ /^9184$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->ClueCon] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [ClueCon] destination_number(77) =~ /^9191$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->show_info] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [show_info] destination_number(77) =~ /^9192$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->video_record] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [video_record] destination_number(77) =~ /^9193$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->video_playback] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [video_playback] destination_number(77) =~ /^9194$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->delay_echo] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [delay_echo] destination_number(77) =~ /^9195$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->echo] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [echo] destination_number(77) =~ /^9196$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->milliwatt] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [milliwatt] destination_number(77) =~ /^9197$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->tone_stream] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [tone_stream] destination_number(77) =~ /^9198$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->zrtp_enrollement] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [zrtp_enrollement] destination_number(77) =~ /^9787$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->hold_music] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [hold_music] destination_number(77) =~ /^9664$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->Recordings] continue=false
2011-09-11 01:17:17.388551 [ERR] switch_regex.c:101 COMPILE ERROR: 1 [nothing to repeat][^*(732)$]
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (FAIL) [Recordings] destination_number(77) =~ /^*(732)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be parsing [default->enum] continue=false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [enum] ${module_exists(mod_enum)}(true) =~ /true/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Regex (PASS) [enum] destination_number(77) =~ /^(.*)$/ break=on-false
Dialplan: sofia/external/0476058096 at voip.belgacom.be Action transfer(77 enum) 
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:128 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_ROUTING -> CS_EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:384 (sofia/external/0476058096 at voip.belgacom.be) State ROUTING going to sleep
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:391 (sofia/external/0476058096 at voip.belgacom.be) State EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] mod_sofia.c:241 sofia/external/0476058096 at voip.belgacom.be SOFIA EXECUTE
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:166 sofia/external/0476058096 at voip.belgacom.be Standard EXECUTE
EXECUTE sofia/external/0476058096 at voip.belgacom.be hash(insert/192.168.1.100-spymap/0476058096/068a829e-dc03-11e0-81f7-f9f410ff919e)
EXECUTE sofia/external/0476058096 at voip.belgacom.be hash(insert/192.168.1.100-last_dial/0476058096/77)
EXECUTE sofia/external/0476058096 at voip.belgacom.be hash(insert/192.168.1.100-last_dial/global/068a829e-dc03-11e0-81f7-f9f410ff919e)
EXECUTE sofia/external/0476058096 at voip.belgacom.be set(RFC2822_DATE=Sun, 11 Sep 2011 01:17:17 +0200)
2011-09-11 01:17:17.388551 [DEBUG] mod_dptools.c:1167 sofia/external/0476058096 at voip.belgacom.be SET [RFC2822_DATE]=[Sun, 11 Sep 2011 01:17:17 +0200]
EXECUTE sofia/external/0476058096 at voip.belgacom.be transfer(77 enum)
2011-09-11 01:17:17.388551 [DEBUG] switch_ivr.c:1693 (sofia/external/0476058096 at voip.belgacom.be) State Change CS_EXECUTE -> CS_ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:1175 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_session.c:724 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:17.388551 [NOTICE] switch_ivr.c:1699 Transfer sofia/external/0476058096 at voip.belgacom.be to enum[77 at default]
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:391 (sofia/external/0476058096 at voip.belgacom.be) State EXECUTE going to sleep
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:336 (sofia/external/0476058096 at voip.belgacom.be) Running State Change CS_ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:384 (sofia/external/0476058096 at voip.belgacom.be) State ROUTING
2011-09-11 01:17:17.388551 [DEBUG] mod_sofia.c:148 sofia/external/0476058096 at voip.belgacom.be SOFIA ROUTING
2011-09-11 01:17:17.388551 [DEBUG] switch_core_state_machine.c:78 sofia/external/0476058096 at voip.belgacom.be Standard ROUTING
2011-09-11 01:17:17.388551 [DEBUG] mod_enum.c:541 ENUM Lookup on 77
2011-09-11 01:17:27.188065 [DEBUG] switch_core_session.c:870 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:27.188065 [DEBUG] switch_core_session.c:870 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]
2011-09-11 01:17:27.188065 [DEBUG] switch_core_session.c:870 Send signal sofia/external/0476058096 at voip.belgacom.be [BREAK]

LOG  INTERNAL -> INTERNAL

2011-09-11 01:22:17.268071 [DEBUG] sofia.c:7057 IP 192.168.100.6 Approved by acl "lan[]". Access Granted.
2011-09-11 01:22:17.268071 [NOTICE] switch_channel.c:908 New Channel sofia/internal/88 at 192.168.1.100 [b94b66fa-dc03-11e0-81f9-f9f410ff919e]
2011-09-11 01:22:17.268071 [DEBUG] sofia.c:5156 Channel sofia/internal/88 at 192.168.1.100 entering state [received][100]
2011-09-11 01:22:17.268071 [DEBUG] sofia.c:5167 Remote SDP:
v=0
o=- 1315696937270159 1 IN IP4 192.168.100.6
s=CounterPath X-Lite 4.1
c=IN IP4 192.168.100.6
t=0 0
a=ice-ufrag:de6e17
a=ice-pwd:9e8391bc4955d13bbf67e8eeb2118613
m=audio 63158 RTP/AVP 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=candidate:1 1 UDP 659136 192.168.100.6 63158 typ host
a=candidate:1 2 UDP 659134 192.168.100.6 63159 typ host

2011-09-11 01:22:17.268071 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_NEW
2011-09-11 01:22:17.268071 [DEBUG] sofia_glue.c:4739 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000]
2011-09-11 01:22:17.268071 [DEBUG] sofia_glue.c:4739 Audio Codec Compare [PCMU:0:8000:20:64000]/[G729:18:8000:20:8000]
2011-09-11 01:22:17.268071 [DEBUG] switch_core_state_machine.c:354 (sofia/internal/88 at 192.168.1.100) State NEW
2011-09-11 01:22:17.268071 [DEBUG] sofia_glue.c:4739 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2011-09-11 01:22:17.268071 [DEBUG] sofia_glue.c:2857 Set Codec sofia/internal/88 at 192.168.1.100 PCMA/8000 20 ms 160 samples 64000 bits
2011-09-11 01:22:17.268071 [DEBUG] sofia_glue.c:4859 Set 2833 dtmf send/recv payload to 101
2011-09-11 01:22:17.268071 [DEBUG] sofia.c:5357 (sofia/internal/88 at 192.168.1.100) State Change CS_NEW -> CS_INIT
2011-09-11 01:22:17.268071 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_INIT
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:375 (sofia/internal/88 at 192.168.1.100) State INIT
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:85 sofia/internal/88 at 192.168.1.100 SOFIA INIT
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:125 (sofia/internal/88 at 192.168.1.100) State Change CS_INIT -> CS_ROUTING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:375 (sofia/internal/88 at 192.168.1.100) State INIT going to sleep
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_ROUTING
2011-09-11 01:22:17.288082 [DEBUG] switch_channel.c:1837 (sofia/internal/88 at 192.168.1.100) Callstate Change DOWN -> RINGING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:384 (sofia/internal/88 at 192.168.1.100) State ROUTING
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:148 sofia/internal/88 at 192.168.1.100 SOFIA ROUTING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:78 sofia/internal/88 at 192.168.1.100 Standard ROUTING
2011-09-11 01:22:17.288082 [INFO] mod_dialplan_xml.c:336 Processing 88 <88>->77 in context public
Dialplan: sofia/internal/88 at 192.168.1.100 parsing [public->unloop] continue=false
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/88 at 192.168.1.100 parsing [public->outside_call] continue=true
Dialplan: sofia/internal/88 at 192.168.1.100 Absolute Condition [outside_call]
Dialplan: sofia/internal/88 at 192.168.1.100 Action set(outside_call=true) 
Dialplan: sofia/internal/88 at 192.168.1.100 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/internal/88 at 192.168.1.100 parsing [public->call_debug] continue=true
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/88 at 192.168.1.100 parsing [public->public_extensions] continue=false
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (FAIL) [public_extensions] destination_number(77) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/88 at 192.168.1.100 parsing [public->015261786] continue=false
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (PASS) [015261786] context(public) =~ /public/ break=on-false
Dialplan: sofia/internal/88 at 192.168.1.100 Regex (FAIL) [015261786] destination_number(77) =~ /^015261786$/ break=on-false
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:128 (sofia/internal/88 at 192.168.1.100) State Change CS_ROUTING -> CS_EXECUTE
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:384 (sofia/internal/88 at 192.168.1.100) State ROUTING going to sleep
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_EXECUTE
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:391 (sofia/internal/88 at 192.168.1.100) State EXECUTE
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:241 sofia/internal/88 at 192.168.1.100 SOFIA EXECUTE
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:166 sofia/internal/88 at 192.168.1.100 Standard EXECUTE
EXECUTE sofia/internal/88 at 192.168.1.100 set(outside_call=true)
2011-09-11 01:22:17.288082 [DEBUG] mod_dptools.c:1167 sofia/internal/88 at 192.168.1.100 SET [outside_call]=[true]
EXECUTE sofia/internal/88 at 192.168.1.100 set(RFC2822_DATE=Sun, 11 Sep 2011 01:22:17 +0200)
2011-09-11 01:22:17.288082 [DEBUG] mod_dptools.c:1167 sofia/internal/88 at 192.168.1.100 SET [RFC2822_DATE]=[Sun, 11 Sep 2011 01:22:17 +0200]
2011-09-11 01:22:17.288082 [NOTICE] switch_core_state_machine.c:200 sofia/internal/88 at 192.168.1.100 has executed the last dialplan instruction, hanging up.
2011-09-11 01:22:17.288082 [DEBUG] switch_channel.c:2797 (sofia/internal/88 at 192.168.1.100) Callstate Change RINGING -> HANGUP
2011-09-11 01:22:17.288082 [NOTICE] switch_core_state_machine.c:202 Hangup sofia/internal/88 at 192.168.1.100 [CS_EXECUTE] [NORMAL_CLEARING]
2011-09-11 01:22:17.288082 [DEBUG] switch_channel.c:2813 Send signal sofia/internal/88 at 192.168.1.100 [KILL]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:391 (sofia/internal/88 at 192.168.1.100) State EXECUTE going to sleep
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_HANGUP
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:576 (sofia/internal/88 at 192.168.1.100) State HANGUP
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:458 Channel sofia/internal/88 at 192.168.1.100 hanging up, cause: NORMAL_CLEARING
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:522 Responding to INVITE with: 480
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:46 sofia/internal/88 at 192.168.1.100 Standard HANGUP, cause: NORMAL_CLEARING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:576 (sofia/internal/88 at 192.168.1.100) State HANGUP going to sleep
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:367 (sofia/internal/88 at 192.168.1.100) State Change CS_HANGUP -> CS_REPORTING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:336 (sofia/internal/88 at 192.168.1.100) Running State Change CS_REPORTING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/88 at 192.168.1.100) State REPORTING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:53 sofia/internal/88 at 192.168.1.100 Standard REPORTING, cause: NORMAL_CLEARING
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/88 at 192.168.1.100) State REPORTING going to sleep
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:361 (sofia/internal/88 at 192.168.1.100) State Change CS_REPORTING -> CS_DESTROY
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1175 Send signal sofia/internal/88 at 192.168.1.100 [BREAK]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_session.c:1349 Session 6 (sofia/internal/88 at 192.168.1.100) Locked, Waiting on external entities
2011-09-11 01:22:17.288082 [NOTICE] switch_core_session.c:1367 Session 6 (sofia/internal/88 at 192.168.1.100) Ended
2011-09-11 01:22:17.288082 [NOTICE] switch_core_session.c:1369 Close Channel sofia/internal/88 at 192.168.1.100 [CS_DESTROY]
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/88 at 192.168.1.100) Callstate Change HANGUP -> DOWN
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:468 (sofia/internal/88 at 192.168.1.100) Running State Change CS_DESTROY
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/88 at 192.168.1.100) State DESTROY
2011-09-11 01:22:17.288082 [DEBUG] mod_sofia.c:363 sofia/internal/88 at 192.168.1.100 SOFIA DESTROY
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:60 sofia/internal/88 at 192.168.1.100 Standard DESTROY
2011-09-11 01:22:17.288082 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/88 at 192.168.1.100) State DESTROY going to sleep