2011-11-18 05:23:23.369854 [NOTICE] switch_channel.c:911 New Channel sofia/external/freeswitch@pbx.toolfactory.net [94b27bf8-11be-11e1-be76-bfe92509c5c7] 2011-11-18 05:23:23.369854 [DEBUG] sofia.c:5261 Channel sofia/external/freeswitch@pbx.toolfactory.net entering state [received][100] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_NEW 2011-11-18 05:23:23.369854 [DEBUG] sofia.c:5272 Remote SDP: v=0 o=FreeSWITCH 1321587633 1321587634 IN IP4 192.168.PB.X2 s=FreeSWITCH c=IN IP4 192.168.PB.X2 t=0 0 m=audio 16970 RTP/AVP 8 18 3 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:380 (sofia/external/freeswitch@pbx.toolfactory.net) State NEW 2011-11-18 05:23:23.369854 [DEBUG] sofia_glue.c:4721 Audio Codec Compare [PCMA:8:8000:20:64000]/[G729:18:8000:20:8000] 2011-11-18 05:23:23.369854 [DEBUG] sofia_glue.c:4721 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2011-11-18 05:23:23.369854 [DEBUG] sofia_glue.c:2842 Set Codec sofia/external/freeswitch@pbx.toolfactory.net PCMA/8000 20 ms 160 samples 64000 bits 2011-11-18 05:23:23.369854 [DEBUG] sofia_glue.c:4842 Set 2833 dtmf send/recv payload to 101 2011-11-18 05:23:23.369854 [DEBUG] sofia.c:5471 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_NEW -> CS_INIT 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_INIT 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:401 (sofia/external/freeswitch@pbx.toolfactory.net) State INIT 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:85 sofia/external/freeswitch@pbx.toolfactory.net SOFIA INIT 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:125 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_INIT -> CS_ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:401 (sofia/external/freeswitch@pbx.toolfactory.net) State INIT going to sleep 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_channel.c:1840 (sofia/external/freeswitch@pbx.toolfactory.net) Callstate Change DOWN -> RINGING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:410 (sofia/external/freeswitch@pbx.toolfactory.net) State ROUTING 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:148 sofia/external/freeswitch@pbx.toolfactory.net SOFIA ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:104 sofia/external/freeswitch@pbx.toolfactory.net Standard ROUTING 2011-11-18 05:23:23.369854 [INFO] mod_dialplan_xml.c:336 Processing Heinrich III S <126>->01140039999 in context public Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [public->unloop] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [public->outside_call] continue=true Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Absolute Condition [outside_call] Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(outside_call=true) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [public->call_debug] continue=true Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [public->public_extensions_o_numeros] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [public_extensions_o_numeros] destination_number(01140039999) =~ /^([1-9][0-9][0-9]|[0-9]{8,15})$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(toll_allow=domestic) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action transfer(01140039999 XML default) 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:154 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_ROUTING -> CS_EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:410 (sofia/external/freeswitch@pbx.toolfactory.net) State ROUTING going to sleep 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:417 (sofia/external/freeswitch@pbx.toolfactory.net) State EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:241 sofia/external/freeswitch@pbx.toolfactory.net SOFIA EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:192 sofia/external/freeswitch@pbx.toolfactory.net Standard EXECUTE EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(outside_call=true) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [outside_call]=[true] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(RFC2822_DATE=Fri, 18 Nov 2011 05:23:23 -0300) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [RFC2822_DATE]=[Fri, 18 Nov 2011 05:23:23 -0300] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(toll_allow=domestic) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [toll_allow]=[domestic] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net transfer(01140039999 XML default) 2011-11-18 05:23:23.369854 [DEBUG] switch_ivr.c:1693 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_EXECUTE -> CS_ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:726 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [NOTICE] switch_ivr.c:1699 Transfer sofia/external/freeswitch@pbx.toolfactory.net to XML[01140039999@default] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:417 (sofia/external/freeswitch@pbx.toolfactory.net) State EXECUTE going to sleep 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:410 (sofia/external/freeswitch@pbx.toolfactory.net) State ROUTING 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:148 sofia/external/freeswitch@pbx.toolfactory.net SOFIA ROUTING 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:104 sofia/external/freeswitch@pbx.toolfactory.net Standard ROUTING 2011-11-18 05:23:23.369854 [INFO] mod_dialplan_xml.c:336 Processing Heinrich III S <126>->01140039999 in context default Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->unloop] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->global-intercept] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [global-intercept] destination_number(01140039999) =~ /^886$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->group-intercept] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [group-intercept] destination_number(01140039999) =~ /^\*8$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->intercept-ext] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [intercept-ext] destination_number(01140039999) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->redial] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [redial] destination_number(01140039999) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->global] continue=true Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Absolute Condition [global] Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(TT_PBX=BR) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->eavesdrop] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [eavesdrop] destination_number(01140039999) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->eavesdrop] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [eavesdrop] destination_number(01140039999) =~ /^779$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->Local_Extension] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [Local_Extension] destination_number(01140039999) =~ /^3?(\d{3})$/ break=never Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [Local_Extension] destination_number(01140039999) =~ /^3?(\d{3})$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(01140039999) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ivr_demo] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ivr_demo] destination_number(01140039999) =~ /^5000$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->wait] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [wait] destination_number(01140039999) =~ /^wait$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->fax_receive] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [fax_receive] destination_number(01140039999) =~ /^9178$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->fax_transmit] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [fax_transmit] destination_number(01140039999) =~ /^9179$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ringback_180] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ringback_180] destination_number(01140039999) =~ /^9180$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ringback_183_uk_ring] destination_number(01140039999) =~ /^9181$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ringback_183_music_ring] destination_number(01140039999) =~ /^9182$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(01140039999) =~ /^9183$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ringback_post_answer_music] destination_number(01140039999) =~ /^9184$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->ClueCon] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [ClueCon] destination_number(01140039999) =~ /^9191$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->show_info] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [show_info] destination_number(01140039999) =~ /^9192$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->delay_echo] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [delay_echo] destination_number(01140039999) =~ /^9195$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->echo] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [echo] destination_number(01140039999) =~ /^9196$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [zrtp_enrollement] destination_number(01140039999) =~ /^9787$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->hold_music] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [hold_music] destination_number(01140039999) =~ /^9664$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->101] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [101] destination_number(01140039999) =~ /^101$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->pizza_demo] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [pizza_demo] destination_number(01140039999) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->Talking Clock Time] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [Talking Clock Time] destination_number(01140039999) =~ /^9170$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->Talking Clock Date] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [Talking Clock Date] destination_number(01140039999) =~ /^9171$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->Talking Clock Date and Time] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [Talking Clock Date and Time] destination_number(01140039999) =~ /^9172$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->spain.landlines] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [spain.landlines] ${toll_allow}(domestic) =~ /domestic/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [spain.landlines] destination_number(01140039999) =~ /^0034(\d*)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->spain.moviles.0034] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [spain.moviles.0034] ${toll_allow}(domestic) =~ /domestic/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [spain.moviles.0034] destination_number(01140039999) =~ /^0034(6\d{8})$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->agent_login] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [agent_login] destination_number(01140039999) =~ /^\*50[03]$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->agent_logoff] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [agent_logoff] destination_number(01140039999) =~ /^\*501$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->agent_onbreak] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (FAIL) [agent_onbreak] destination_number(01140039999) =~ /^\*502$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net parsing [default->Airtel] continue=false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [Airtel] ${toll_allow}(domestic) =~ /domestic/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [Airtel] caller_id_number(126) =~ /^(803|101|126)$/ break=on-false Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Regex (PASS) [Airtel] destination_number(01140039999) =~ /^(\d\d\d\d\d\d\d\d*)$/ break=on-true Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action set(media_bug_answer_req=true) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action privacy(full) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action record_session(/usr/local/freeswitch/recordings/queues/${strftime(%Y-%m-%d-%H-%M-%S)}.${caller_id_number}.${destination_number}.${uuid}.wav) Dialplan: sofia/external/freeswitch@pbx.toolfactory.net Action bridge({sip_cid_type=rpid}sofia/gateway/airtel.net.br/01140039999) 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:154 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_ROUTING -> CS_EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:410 (sofia/external/freeswitch@pbx.toolfactory.net) State ROUTING going to sleep 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:417 (sofia/external/freeswitch@pbx.toolfactory.net) State EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] mod_sofia.c:241 sofia/external/freeswitch@pbx.toolfactory.net SOFIA EXECUTE 2011-11-18 05:23:23.369854 [DEBUG] switch_core_state_machine.c:192 sofia/external/freeswitch@pbx.toolfactory.net Standard EXECUTE EXECUTE sofia/external/freeswitch@pbx.toolfactory.net hash(insert/192.168.PB.X-spymap/126/94b27bf8-11be-11e1-be76-bfe92509c5c7) EXECUTE sofia/external/freeswitch@pbx.toolfactory.net hash(insert/192.168.PB.X-last_dial/126/01140039999) EXECUTE sofia/external/freeswitch@pbx.toolfactory.net hash(insert/192.168.PB.X-last_dial/global/94b27bf8-11be-11e1-be76-bfe92509c5c7) EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(RFC2822_DATE=Fri, 18 Nov 2011 05:23:23 -0300) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [RFC2822_DATE]=[Fri, 18 Nov 2011 05:23:23 -0300] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(TT_PBX=BR) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [TT_PBX]=[BR] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net set(media_bug_answer_req=true) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1177 sofia/external/freeswitch@pbx.toolfactory.net SET [media_bug_answer_req]=[true] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net privacy(full) 2011-11-18 05:23:23.369854 [DEBUG] mod_dptools.c:1426 Set Privacy to full [7] 2011-11-18 05:23:23.369854 [DEBUG] switch_core_session.c:2109 Application record_session Requires media! pre_answering channel sofia/external/freeswitch@pbx.toolfactory.net 2011-11-18 05:23:23.369854 [INFO] switch_core_session.c:2111 Sending early media 2011-11-18 05:23:23.369854 [INFO] switch_nat.c:589 NAT port mapping disabled 2011-11-18 05:23:23.369854 [INFO] switch_nat.c:589 NAT port mapping disabled 2011-11-18 05:23:23.369854 [DEBUG] sofia_glue.c:3094 AUDIO RTP [sofia/external/freeswitch@pbx.toolfactory.net] 192.168.PB.X port 30282 -> 192.168.PB.X2 port 16970 codec: 8 ms: 20 2011-11-18 05:23:23.369854 [DEBUG] switch_rtp.c:1642 Starting timer [soft] 160 bytes per 20ms 2011-11-18 05:23:23.408823 [DEBUG] sofia_glue.c:3357 Set 2833 dtmf send payload to 101 2011-11-18 05:23:23.408823 [DEBUG] sofia_glue.c:3363 Set 2833 dtmf receive payload to 101 2011-11-18 05:23:23.408823 [DEBUG] sofia_glue.c:3382 Set comfort noise payload to 13 2011-11-18 05:23:23.408823 [DEBUG] mod_sofia.c:2471 Ring SDP: v=0 o=FreeSWITCH 1321574321 1321574322 IN IP4 187.103.My.IP s=FreeSWITCH c=IN IP4 187.103.My.IP t=0 0 m=audio 30282 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv 2011-11-18 05:23:23.408823 [NOTICE] mod_sofia.c:2474 Pre-Answer sofia/external/freeswitch@pbx.toolfactory.net! 2011-11-18 05:23:23.408823 [DEBUG] switch_channel.c:2877 (sofia/external/freeswitch@pbx.toolfactory.net) Callstate Change RINGING -> EARLY 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:726 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] EXECUTE sofia/external/freeswitch@pbx.toolfactory.net record_session(/usr/local/freeswitch/recordings/queues/2011-11-18-05-23-23.126.01140039999.94b27bf8-11be-11e1-be76-bfe92509c5c7.wav) 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] sofia.c:5254 Channel sofia/external/freeswitch@pbx.toolfactory.net skipping state [early][183] 2011-11-18 05:23:23.408823 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/external/freeswitch@pbx.toolfactory.net EXECUTE sofia/external/freeswitch@pbx.toolfactory.net bridge({sip_cid_type=rpid}sofia/gateway/airtel.net.br/01140039999) 2011-11-18 05:23:23.408823 [DEBUG] switch_ivr_originate.c:1882 Parsing global variables 2011-11-18 05:23:23.408823 [DEBUG] switch_event.c:1521 Parsing variable [sip_cid_type]=[rpid] 2011-11-18 05:23:23.408823 [NOTICE] switch_channel.c:911 New Channel sofia/external-test/01140039999 [94b409d2-11be-11e1-be7b-bfe92509c5c7] 2011-11-18 05:23:23.408823 [DEBUG] mod_sofia.c:4504 (sofia/external-test/01140039999) State Change CS_NEW -> CS_INIT 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_INIT 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:401 (sofia/external-test/01140039999) State INIT 2011-11-18 05:23:23.408823 [DEBUG] mod_sofia.c:85 sofia/external-test/01140039999 SOFIA INIT 2011-11-18 05:23:23.408823 [INFO] switch_nat.c:589 NAT port mapping disabled 2011-11-18 05:23:23.408823 [INFO] switch_nat.c:589 NAT port mapping disabled 2011-11-18 05:23:23.408823 [DEBUG] mod_sofia.c:125 (sofia/external-test/01140039999) State Change CS_INIT -> CS_ROUTING 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:401 (sofia/external-test/01140039999) State INIT going to sleep 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_ROUTING 2011-11-18 05:23:23.408823 [DEBUG] switch_channel.c:1840 (sofia/external-test/01140039999) Callstate Change DOWN -> RINGING 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:410 (sofia/external-test/01140039999) State ROUTING 2011-11-18 05:23:23.408823 [DEBUG] mod_sofia.c:148 sofia/external-test/01140039999 SOFIA ROUTING 2011-11-18 05:23:23.408823 [DEBUG] switch_ivr_originate.c:66 (sofia/external-test/01140039999) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:410 (sofia/external-test/01140039999) State ROUTING going to sleep 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_CONSUME_MEDIA send 1148 bytes to udp/[187.111.X.Y]:5060 at 08:23:23.412094: ------------------------------------------------------------------------ INVITE sip:01140039999@airtel.net.br SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bKX5664pQgrFcjj 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:429 (sofia/external-test/01140039999) State CONSUME_MEDIA Max-Forwards: 67 From: "Heinrich III S" ;tag=NyvaUBt4440rF 2011-11-18 05:23:23.408823 [DEBUG] switch_core_state_machine.c:429 (sofia/external-test/01140039999) State CONSUME_MEDIA going to sleep To: Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466237 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Allow-Events: talk, hold, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 229 X-Serialnumber: 0004132F2C10 P-Key-Flags: keys="3" X-FS-Support: update_display Remote-Party-ID: "Heinrich III S" ;party=calling;screen=yes;privacy=full v=0 o=FreeSWITCH 1321577747 1321577748 IN IP4 187.103.My.IP s=FreeSWITCH c=IN IP4 187.103.My.IP t=0 0 m=audio 26856 RTP/AVP 8 18 0 101 13 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [calling][0] recv 500 bytes from udp/[187.111.X.Y]:5060 at 08:23:23.415726: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.PB.X:5085;rport=5085;branch=z9hG4bKX5664pQgrFcjj From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=2f9e69b4a1bb2c59a9904e778b04fdd7.eaef Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466237 INVITE Proxy-Authenticate: Digest realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98" Server: SIP Pulse 1.2 Content-Length: 0 ------------------------------------------------------------------------ send 377 bytes to udp/[187.111.X.Y]:5060 at 08:23:23.415884: ------------------------------------------------------------------------ ACK sip:01140039999@airtel.net.br SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bKX5664pQgrFcjj Max-Forwards: 67 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=2f9e69b4a1bb2c59a9904e778b04fdd7.eaef Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466237 ACK Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] sofia_reg.c:2140 Authenticating 'USERNAME' with 'Digest:"airtel.net.br":USERNAME:PASSWORD'. send 1386 bytes to udp/[187.111.X.Y]:5060 at 08:23:23.416295: ------------------------------------------------------------------------ INVITE sip:01140039999@airtel.net.br SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bKye0Z6H8KNr24D Max-Forwards: 67 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466238 INVITE Contact: Expires: 60 User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Allow-Events: talk, hold, refer Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:01140039999@airtel.net.br", response="257c05bcfb64448a0f3381cbdb5b0520" Content-Type: application/sdp Content-Disposition: session Content-Length: 229 X-Serialnumber: 0004132F2C10 P-Key-Flags: keys="3" X-FS-Support: update_display Remote-Party-ID: "Heinrich III S" ;party=calling;screen=yes;privacy=full v=0 o=FreeSWITCH 1321577747 1321577748 IN IP4 187.103.My.IP s=FreeSWITCH c=IN IP4 187.103.My.IP t=0 0 m=audio 26856 RTP/AVP 8 18 0 101 13 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2011-11-18 05:23:23.408823 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:23.408823 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [calling][0] recv 333 bytes from udp/[187.111.X.Y]:5060 at 08:23:23.420991: ------------------------------------------------------------------------ SIP/2.0 100 Giving a try Via: SIP/2.0/UDP 192.168.PB.X:5085;rport=5085;branch=z9hG4bKye0Z6H8KNr24D From: "Heinrich III S" ;tag=NyvaUBt4440rF To: Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466238 INVITE Server: SIP Pulse 1.2 Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:23.468865 [DEBUG] sofia_reg.c:1399 Send challenge for [460@192.168.PB.X] 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '460' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Rodrigo' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '460' 2011-11-18 05:23:23.828902 [DEBUG] sofia_reg.c:1549 Register: From: [460@192.168.PB.X] Contact: ["Rodrigo" ] Expires: [120] 2011-11-18 05:23:24.029812 [INFO] switch_rtp.c:3164 Auto Changing port from 192.168.PB.X2:16970 to 213.97.PBX.2:16970 2011-11-18 05:23:26.790018 [DEBUG] sofia_reg.c:1399 Send challenge for [463@192.168.PB.X] 2011-11-18 05:23:27.149841 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:23:27.149841 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:23:27.149841 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:23:27.149841 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:23:27.149841 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:23:27.188825 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '463' 2011-11-18 05:23:27.188825 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:23:27.188825 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Luis' 2011-11-18 05:23:27.188825 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '463' 2011-11-18 05:23:27.188825 [DEBUG] sofia_reg.c:1549 Register: From: [463@192.168.PB.X] Contact: ["Luis" ] Expires: [120] recv 636 bytes from udp/[187.111.X.Y]:5060 at 08:23:29.365405: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bKye0Z6H8KNr24D Record-Route: From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 CSeq: 20466238 INVITE ------------------------------------------------------------------------ 2011-11-18 05:23:29.348910 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.348910 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.348910 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [proceeding][180] 2011-11-18 05:23:29.348910 [NOTICE] sofia.c:5340 Ring-Ready sofia/external-test/01140039999! recv 1011 bytes from udp/[187.111.X.Y]:5060 at 08:23:29.365917: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bKye0Z6H8KNr24D Record-Route: From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 333 CSeq: 20466238 INVITE v=0 o=root 859610555 859610555 IN IP4 187.111.X.Z s=Asterisk PBX 1.6.1.20 c=IN IP4 187.111.X.Z t=0 0 m=audio 10798 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv ------------------------------------------------------------------------ 2011-11-18 05:23:29.348910 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.348910 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.348910 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [proceeding][183] 2011-11-18 05:23:29.348910 [DEBUG] sofia.c:5272 Remote SDP: v=0 o=root 859610555 859610555 IN IP4 187.111.X.Z s=Asterisk PBX 1.6.1.20 c=IN IP4 187.111.X.Z t=0 0 m=audio 10798 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:4721 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000] 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:4721 Audio Codec Compare [PCMU:0:8000:20:64000]/[G729:18:8000:20:8000] 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:4721 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:2842 Set Codec sofia/external-test/01140039999 PCMU/8000 20 ms 160 samples 64000 bits 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:4835 Set 2833 dtmf send payload to 101 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:3094 AUDIO RTP [sofia/external-test/01140039999] 192.168.PB.X port 26856 -> 187.111.X.Z port 10798 codec: 0 ms: 20 2011-11-18 05:23:29.348910 [DEBUG] switch_rtp.c:1642 Starting timer [soft] 160 bytes per 20ms 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:3357 Set 2833 dtmf send payload to 101 2011-11-18 05:23:29.348910 [DEBUG] sofia_glue.c:3363 Set 2833 dtmf receive payload to 101 2011-11-18 05:23:29.348910 [NOTICE] sofia_glue.c:3869 Pre-Answer sofia/external-test/01140039999! 2011-11-18 05:23:29.348910 [DEBUG] switch_channel.c:2877 (sofia/external-test/01140039999) Callstate Change RINGING -> EARLY 2011-11-18 05:23:29.368828 [DEBUG] switch_channel.c:2919 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:29.369825 [DEBUG] switch_ivr_originate.c:3252 Originate Resulted in Success: [sofia/external-test/01140039999] 2011-11-18 05:23:29.369825 [DEBUG] switch_core_session.c:726 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.369825 [DEBUG] switch_core_session.c:726 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:29.369825 [DEBUG] switch_ivr_bridge.c:1257 (sofia/external-test/01140039999) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2011-11-18 05:23:29.369825 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:29.369825 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_EXCHANGE_MEDIA 2011-11-18 05:23:29.369825 [DEBUG] switch_core_state_machine.c:420 (sofia/external-test/01140039999) State EXCHANGE_MEDIA 2011-11-18 05:23:29.369825 [DEBUG] mod_sofia.c:573 SOFIA EXCHANGE_MEDIA 2011-11-18 05:23:29.489889 [DEBUG] switch_rtp.c:3181 Correct ip/port confirmed. 2011-11-18 05:23:33.329818 [DEBUG] sofia_reg.c:1399 Send challenge for [465@192.168.PB.X] 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '465' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Sofia Oliveira' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '465' 2011-11-18 05:23:33.689832 [DEBUG] sofia_reg.c:1549 Register: From: [465@192.168.PB.X] Contact: ["Sofia" ] Expires: [120] 2011-11-18 05:23:35.669825 [DEBUG] sofia_reg.c:1399 Send challenge for [462@192.168.PB.X] 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '462' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Vera' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '462' 2011-11-18 05:23:36.029822 [DEBUG] sofia_reg.c:1549 Register: From: [462@192.168.PB.X] Contact: ["Vera" ] Expires: [120] recv 997 bytes from udp/[187.111.X.Y]:5060 at 08:23:36.136588: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bKye0Z6H8KNr24D Record-Route: From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 333 CSeq: 20466238 INVITE v=0 o=root 859610555 859610556 IN IP4 187.111.X.Z s=Asterisk PBX 1.6.1.20 c=IN IP4 187.111.X.Z t=0 0 m=audio 10798 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv ------------------------------------------------------------------------ 2011-11-18 05:23:36.128900 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.128900 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.149831 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [completing][200] 2011-11-18 05:23:36.149831 [DEBUG] sofia.c:5272 Remote SDP: v=0 o=root 859610555 859610556 IN IP4 187.111.X.Z s=Asterisk PBX 1.6.1.20 c=IN IP4 187.111.X.Z t=0 0 m=audio 10798 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 send 715 bytes to udp/[187.111.X.Y]:5060 at 08:23:36.150449: ------------------------------------------------------------------------ ACK sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bKZQSr8cSQj1rQS Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466238 ACK Contact: Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:01140039999@airtel.net.br", response="257c05bcfb64448a0f3381cbdb5b0520" Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:36.149831 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.149831 [DEBUG] switch_core_session.c:872 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.188889 [DEBUG] sofia.c:5261 Channel sofia/external-test/01140039999 entering state [ready][200] 2011-11-18 05:23:36.188889 [DEBUG] switch_channel.c:3135 (sofia/external-test/01140039999) Callstate Change EARLY -> ACTIVE 2011-11-18 05:23:36.188889 [DEBUG] switch_channel.c:3147 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.188889 [NOTICE] sofia.c:5887 Channel [sofia/external-test/01140039999] has been answered 2011-11-18 05:23:36.209803 [DEBUG] mod_sofia.c:745 Local SDP sofia/external/freeswitch@pbx.toolfactory.net: v=0 o=FreeSWITCH 1321574321 1321574323 IN IP4 187.103.My.IP s=FreeSWITCH c=IN IP4 187.103.My.IP t=0 0 m=audio 30282 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv 2011-11-18 05:23:36.209803 [DEBUG] switch_core_session.c:726 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.209803 [DEBUG] switch_channel.c:3135 (sofia/external/freeswitch@pbx.toolfactory.net) Callstate Change EARLY -> ACTIVE 2011-11-18 05:23:36.209803 [NOTICE] switch_ivr_bridge.c:417 Channel [sofia/external/freeswitch@pbx.toolfactory.net] has been answered 2011-11-18 05:23:36.209803 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.209803 [DEBUG] sofia.c:5261 Channel sofia/external/freeswitch@pbx.toolfactory.net entering state [completed][200] 2011-11-18 05:23:36.569821 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.569821 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.569821 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.608843 [DEBUG] sofia.c:5261 Channel sofia/external/freeswitch@pbx.toolfactory.net entering state [ready][200] 2011-11-18 05:23:36.608843 [DEBUG] switch_core_session.c:788 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.608843 [DEBUG] switch_core_session.c:788 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.668907 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:36.689799 [INFO] sofia.c:769 sofia/external/freeswitch@pbx.toolfactory.net Update Callee ID to "Heinrich III Sacherer" <126> 2011-11-18 05:23:36.689799 [DEBUG] switch_core_session.c:788 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:36.689799 [DEBUG] sofia.c:6987 dispatched freeswitch event for INFO 2011-11-18 05:23:43.829832 [DEBUG] sofia_reg.c:1399 Send challenge for [126@192.168.PB.X] 2011-11-18 05:23:44.189834 [DEBUG] sofia_reg.c:1354 Send forbidden for [126@192.168.PB.X] 2011-11-18 05:23:44.789843 [NOTICE] sofia_reg.c:371 Registering airtel.net.br send 885 bytes to udp/[187.111.X.Y]:5060 at 08:23:44.826275: ------------------------------------------------------------------------ REGISTER sip:airtel.net.br;transport=udp SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK00jHa89tFaFaN Max-Forwards: 70 From: ;tag=ggNNS2a2FU84j To: Call-ID: 16b1a730-1117-11e1-8f7f-bfe92509c5c7 CSeq: 20432620 REGISTER Contact: Expires: 60 User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec615ef0000a5f05972d51a95cc80c8a2532a09348bae5d", algorithm=MD5, uri="sip:airtel.net.br;transport=udp", response="dd21657293ee73f5156c8e509b45f278" Content-Length: 0 ------------------------------------------------------------------------ recv 492 bytes from udp/[187.111.X.Y]:5060 at 08:23:44.829807: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.PB.X:5085;rport=5085;branch=z9hG4bK00jHa89tFaFaN From: ;tag=ggNNS2a2FU84j To: ;tag=2f9e69b4a1bb2c59a9904e778b04fdd7.17af Call-ID: 16b1a730-1117-11e1-8f7f-bfe92509c5c7 CSeq: 20432620 REGISTER WWW-Authenticate: Digest realm="airtel.net.br", nonce="4ec6162d0000a61a94a866927995644371603879becabad1", stale=true Server: SIP Pulse 1.2 Content-Length: 0 ------------------------------------------------------------------------ send 885 bytes to udp/[187.111.X.Y]:5060 at 08:23:44.829992: ------------------------------------------------------------------------ REGISTER sip:airtel.net.br;transport=udp SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK19Bac3tycK5vg Max-Forwards: 70 From: ;tag=ggNNS2a2FU84j To: Call-ID: 16b1a730-1117-11e1-8f7f-bfe92509c5c7 CSeq: 20432621 REGISTER Contact: Expires: 60 User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec6162d0000a61a94a866927995644371603879becabad1", algorithm=MD5, uri="sip:airtel.net.br;transport=udp", response="33ea6ad3669924a43dfd323906e1e9b3" Content-Length: 0 ------------------------------------------------------------------------ recv 448 bytes from udp/[187.111.X.Y]:5060 at 08:23:44.833168: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.PB.X:5085;rport=5085;branch=z9hG4bK19Bac3tycK5vg From: ;tag=ggNNS2a2FU84j To: ;tag=2f9e69b4a1bb2c59a9904e778b04fdd7.0293 Call-ID: 16b1a730-1117-11e1-8f7f-bfe92509c5c7 CSeq: 20432621 REGISTER Contact: ;expires=60 Server: SIP Pulse 1.2 Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:45.809839 [DEBUG] sofia_reg.c:335 Registered airtel.net.br 2011-11-18 05:23:47.609816 [DEBUG] switch_core_session.c:872 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:499 sofia/external/freeswitch@pbx.toolfactory.net ending bridge by request from write function 2011-11-18 05:23:47.648898 [DEBUG] switch_channel.c:2800 (sofia/external/freeswitch@pbx.toolfactory.net) Callstate Change ACTIVE -> HANGUP 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/external-test/01140039999] 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:606 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_channel.c:2800 (sofia/external-test/01140039999) Callstate Change ACTIVE -> HANGUP 2011-11-18 05:23:47.648898 [NOTICE] sofia.c:573 Hangup sofia/external/freeswitch@pbx.toolfactory.net [CS_EXECUTE] [NORMAL_CLEARING] 2011-11-18 05:23:47.648898 [NOTICE] switch_ivr_bridge.c:658 Hangup sofia/external-test/01140039999 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2011-11-18 05:23:47.648898 [DEBUG] switch_channel.c:2816 Send signal sofia/external/freeswitch@pbx.toolfactory.net [KILL] 2011-11-18 05:23:47.648898 [DEBUG] switch_channel.c:2816 Send signal sofia/external-test/01140039999 [KILL] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:420 (sofia/external-test/01140039999) State EXCHANGE_MEDIA going to sleep 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_HANGUP 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:586 BRIDGE THREAD DONE [sofia/external/freeswitch@pbx.toolfactory.net] 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:606 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external-test/01140039999) State HANGUP 2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:459 sofia/external-test/01140039999 Overriding SIP cause 480 with 200 from the other leg 2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:465 Channel sofia/external-test/01140039999 hanging up, cause: NORMAL_CLEARING 2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:508 Sending BYE to sofia/external-test/01140039999 send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:47.650139: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:47 sofia/external-test/01140039999 Standard HANGUP, cause: NORMAL_CLEARING Supported: 100rel, timer, precondition, path, replaces 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external-test/01140039999) State HANGUP going to sleep Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:393 (sofia/external-test/01140039999) State Change CS_HANGUP -> CS_REPORTING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external-test/01140039999) Running State Change CS_REPORTING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:662 (sofia/external-test/01140039999) State REPORTING 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:1332 sofia/external-test/01140039999 skip receive message [UNBRIDGE] (channel is hungup already) 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_bridge.c:1335 sofia/external/freeswitch@pbx.toolfactory.net skip receive message [UNBRIDGE] (channel is hungup already) 2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:2261 sofia/external/freeswitch@pbx.toolfactory.net skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:417 (sofia/external/freeswitch@pbx.toolfactory.net) State EXECUTE going to sleep 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_HANGUP 2011-11-18 05:23:47.648898 [DEBUG] switch_ivr_async.c:978 Stop recording file /usr/local/freeswitch/recordings/queues/2011-11-18-05-23-23.126.01140039999.94b27bf8-11be-11e1-be76-bfe92509c5c7.wav 2011-11-18 05:23:47.648898 [DEBUG] switch_core_media_bug.c:480 Removing BUG from sofia/external/freeswitch@pbx.toolfactory.net 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external/freeswitch@pbx.toolfactory.net) State HANGUP 2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:459 sofia/external/freeswitch@pbx.toolfactory.net Overriding SIP cause 480 with 200 from the other leg 2011-11-18 05:23:47.648898 [DEBUG] mod_sofia.c:465 Channel sofia/external/freeswitch@pbx.toolfactory.net hanging up, cause: NORMAL_CLEARING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:47 sofia/external/freeswitch@pbx.toolfactory.net Standard HANGUP, cause: NORMAL_CLEARING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:602 (sofia/external/freeswitch@pbx.toolfactory.net) State HANGUP going to sleep 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:393 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_HANGUP -> CS_REPORTING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:362 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_REPORTING 2011-11-18 05:23:47.648898 [DEBUG] switch_core_state_machine.c:662 (sofia/external/freeswitch@pbx.toolfactory.net) State REPORTING recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:47.653748: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:48.652955: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:48.656032: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:79 sofia/external-test/01140039999 Standard REPORTING, cause: NORMAL_CLEARING 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:662 (sofia/external-test/01140039999) State REPORTING going to sleep 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:387 (sofia/external-test/01140039999) State Change CS_REPORTING -> CS_DESTROY 2011-11-18 05:23:49.328907 [DEBUG] switch_core_session.c:1177 Send signal sofia/external-test/01140039999 [BREAK] 2011-11-18 05:23:49.328907 [DEBUG] switch_core_session.c:1377 Session 11055 (sofia/external-test/01140039999) Locked, Waiting on external entities 2011-11-18 05:23:49.328907 [NOTICE] switch_core_session.c:1395 Session 11055 (sofia/external-test/01140039999) Ended 2011-11-18 05:23:49.328907 [NOTICE] switch_core_session.c:1397 Close Channel sofia/external-test/01140039999 [CS_DESTROY] 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:491 (sofia/external-test/01140039999) Callstate Change HANGUP -> DOWN 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:494 (sofia/external-test/01140039999) Running State Change CS_DESTROY 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:504 (sofia/external-test/01140039999) State DESTROY 2011-11-18 05:23:49.328907 [DEBUG] mod_sofia.c:370 sofia/external-test/01140039999 SOFIA DESTROY 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:86 sofia/external-test/01140039999 Standard DESTROY 2011-11-18 05:23:49.328907 [DEBUG] switch_core_state_machine.c:504 (sofia/external-test/01140039999) State DESTROY going to sleep 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:79 sofia/external/freeswitch@pbx.toolfactory.net Standard REPORTING, cause: NORMAL_CLEARING 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:662 (sofia/external/freeswitch@pbx.toolfactory.net) State REPORTING going to sleep 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:387 (sofia/external/freeswitch@pbx.toolfactory.net) State Change CS_REPORTING -> CS_DESTROY 2011-11-18 05:23:49.508907 [DEBUG] switch_core_session.c:1177 Send signal sofia/external/freeswitch@pbx.toolfactory.net [BREAK] 2011-11-18 05:23:49.508907 [DEBUG] switch_core_session.c:1377 Session 11054 (sofia/external/freeswitch@pbx.toolfactory.net) Locked, Waiting on external entities 2011-11-18 05:23:49.508907 [NOTICE] switch_core_session.c:1395 Session 11054 (sofia/external/freeswitch@pbx.toolfactory.net) Ended 2011-11-18 05:23:49.508907 [NOTICE] switch_core_session.c:1397 Close Channel sofia/external/freeswitch@pbx.toolfactory.net [CS_DESTROY] 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:491 (sofia/external/freeswitch@pbx.toolfactory.net) Callstate Change HANGUP -> DOWN 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:494 (sofia/external/freeswitch@pbx.toolfactory.net) Running State Change CS_DESTROY 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:504 (sofia/external/freeswitch@pbx.toolfactory.net) State DESTROY 2011-11-18 05:23:49.508907 [DEBUG] mod_sofia.c:370 sofia/external/freeswitch@pbx.toolfactory.net SOFIA DESTROY 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:86 sofia/external/freeswitch@pbx.toolfactory.net Standard DESTROY 2011-11-18 05:23:49.508907 [DEBUG] switch_core_state_machine.c:504 (sofia/external/freeswitch@pbx.toolfactory.net) State DESTROY going to sleep send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:50.653194: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 461 bytes from udp/[187.111.X.Y]:5060 at 08:23:50.656440: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:54.653194: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 494 bytes from udp/[187.111.X.Y]:5060 at 08:23:54.656920: ------------------------------------------------------------------------ SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:23:55.469827 [DEBUG] sofia_reg.c:1399 Send challenge for [273@192.168.PB.X] 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '273' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Martin M.' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '273' 2011-11-18 05:23:55.829775 [DEBUG] sofia_reg.c:1549 Register: From: [273@192.168.PB.X] Contact: ["Martin M." ] Expires: [120] send 997 bytes to udp/[187.111.X.Y]:5060 at 08:23:58.652937: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 494 bytes from udp/[187.111.X.Y]:5060 at 08:23:58.656262: ------------------------------------------------------------------------ SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ send 997 bytes to udp/[187.111.X.Y]:5060 at 08:24:02.656941: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 494 bytes from udp/[187.111.X.Y]:5060 at 08:24:02.660800: ------------------------------------------------------------------------ SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 192.168.PB.X:5085;received=192.168.PB.X;rport=5085;branch=z9hG4bK2j52DyB29UUFc From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 2147483647 BYE Server: Airtel Gateway Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 ------------------------------------------------------------------------ 2011-11-18 05:24:05.249817 [DEBUG] sofia_reg.c:1399 Send challenge for [511@192.168.PB.X] 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'record_stereo' = 'true' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_gateway' = 'example.com' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'default_areacode' = '918' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'transfer_fallback_extension' = 'operator' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'toll_allow' = 'domestic,international,local' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'accountcode' = '511' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'user_context' = 'default' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_name' = 'Rafael Goncalo' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:2672 event_add_header -> 'effective_caller_id_number' = '511' 2011-11-18 05:24:05.609848 [DEBUG] sofia_reg.c:1549 Register: From: [511@192.168.PB.X] Contact: ["Rafael Goncalo" ] Expires: [120] send 997 bytes to udp/[187.111.X.Y]:5060 at 08:24:06.656950: ------------------------------------------------------------------------ BYE sip:0231140039999@187.111.X.Z SIP/2.0 Via: SIP/2.0/UDP 187.103.My.IP:5085;rport;branch=z9hG4bK2j52DyB29UUFc Route: Max-Forwards: 70 From: "Heinrich III S" ;tag=NyvaUBt4440rF To: ;tag=as62aa2285 Call-ID: 6c126984-8c61-122f-7e82-782bcb2cab60 CSeq: 20466239 BYE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-10df279 2011-10-15 07-59-23 -0500 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, PRACK, NOTIFY Supported: 100rel, timer, precondition, path, replaces Proxy-Authorization: Digest username="USERNAME", realm="airtel.net.br", nonce="4ec616180000a60f73db499833afd9f3ec0df8d64801dd98", algorithm=MD5, uri="sip:0231140039999@187.111.X.Z", response="4877c4af90e769ed87bc7c17c5ddfcf3" Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------