recv 1138 bytes from udp/[172.xx.xx.3]:65516 at 09:01:06.315556: ------------------------------------------------------------------------ INVITE sip:4099@172.31.35.60:5060 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A23191E From: ;tag=2E56AF64-2516 To: Date: Fri, 04 Nov 2016 06:53:00 GMT Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 Supported: 100rel,timer,resource-priority,replaces,sdp-anat Min-SE: 1800 Cisco-Guid: 2077484416-0000065536-0000007231-1678944448 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Timestamp: 1478242380 Contact: Expires: 180 Allow-Events: telephone-event Max-Forwards: 68 Session-Expires: 1800 Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 324 v=0 o=CiscoSystemsSIP-GW-UserAgent 6493 8918 IN IP4 172.xx.xx.3 s=SIP Call c=IN IP4 172.xx.xx.3 t=0 0 m=audio 18436 RTP/AVP 18 101 121 c=IN IP4 172.xx.xx.3 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:121 frf-dialed-digit/8000 a=fmtp:121 0-15 a=ptime:20 ------------------------------------------------------------------------ send 364 bytes to udp/[172.xx.xx.3]:5060 at 09:01:06.315896: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A23191E From: ;tag=2E56AF64-2516 To: Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 CSeq: 101 INVITE Timestamp: 1478242380 0.000131 User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:06.297602 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/8003@172.xx.xx.3 [ffefcfb3-be10-472d-8469-40692b7457da] 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_NEW 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:9374 sofia/internal/8003@172.xx.xx.3 receiving invite from 172.xx.xx.3:65516 version: 1.6.7 git f0c3870 2016-04-01 13:40:07Z 64bit 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:9486 IP 172.xx.xx.3 Approved by acl "domains[]". Access Granted. 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:10676 Setting NAT mode based on via port 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [received][100] 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:6868 Remote SDP: v=0 o=CiscoSystemsSIP-GW-UserAgent 6493 8918 IN IP4 172.xx.xx.3 s=SIP Call c=IN IP4 172.xx.xx.3 t=0 0 m=audio 18436 RTP/AVP 18 101 121 c=IN IP4 172.xx.xx.3 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:121 frf-dialed-digit/8000 a=fmtp:121 0-15 a=ptime:20 2016-11-04 09:01:06.297602 [DEBUG] sofia.c:7227 (sofia/internal/8003@172.xx.xx.3) State Change CS_NEW -> CS_INIT 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/8003@172.xx.xx.3) State NEW 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_INIT 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/8003@172.xx.xx.3) State INIT 2016-11-04 09:01:06.297602 [DEBUG] mod_sofia.c:89 sofia/internal/8003@172.xx.xx.3 SOFIA INIT 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:40 sofia/internal/8003@172.xx.xx.3 Standard INIT 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/8003@172.xx.xx.3) State Change CS_INIT -> CS_ROUTING 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/8003@172.xx.xx.3) State INIT going to sleep 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_ROUTING 2016-11-04 09:01:06.297602 [DEBUG] switch_channel.c:2249 (sofia/internal/8003@172.xx.xx.3) Callstate Change DOWN -> RINGING 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING 2016-11-04 09:01:06.297602 [DEBUG] mod_sofia.c:142 sofia/internal/8003@172.xx.xx.3 SOFIA ROUTING 2016-11-04 09:01:06.297602 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8003@172.xx.xx.3 Standard ROUTING 2016-11-04 09:01:06.297602 [INFO] mod_dialplan_xml.c:637 Processing 8003 <8003>->4099 in context public Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->unloop] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_huntgroup] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_huntgroup] destination_number(4099) =~ /^0870980891$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_did_to_local] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_did_to_local] destination_number(4099) =~ /^0870980892$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->outside_call] continue=true Dialplan: sofia/internal/8003@172.xx.xx.3 Absolute Condition [outside_call] Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(outside_call=true) Dialplan: sofia/internal/8003@172.xx.xx.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->call_debug] continue=true Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_extensions] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_extensions] destination_number(4099) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(5551212)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(0870980892)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980890$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980893$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->conf11001] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [conf11001] destination_number(4099) =~ /^11001$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->UNKNOWN] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [UNKNOWN] destination_number(4099) =~ /^(4099)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(transfer_after_bridge=4099) Dialplan: sofia/internal/8003@172.xx.xx.3 Action sleep(300) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set uuid ${caller_id_number} '${uuid}')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set type ${caller_id_number} 'uuid-standby')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set status ${caller_id_number} 'Available')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set state ${caller_id_number} 'idle')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3) Dialplan: sofia/internal/8003@172.xx.xx.3 Action answer() Dialplan: sofia/internal/8003@172.xx.xx.3 Action playback(local_stream://moh) 2016-11-04 09:01:06.317476 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8003@172.xx.xx.3) State Change CS_ROUTING -> CS_EXECUTE 2016-11-04 09:01:06.317476 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING going to sleep 2016-11-04 09:01:06.317476 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXECUTE 2016-11-04 09:01:06.317476 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE 2016-11-04 09:01:06.317476 [DEBUG] mod_sofia.c:197 sofia/internal/8003@172.xx.xx.3 SOFIA EXECUTE 2016-11-04 09:01:06.317476 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8003@172.xx.xx.3 Standard EXECUTE EXECUTE sofia/internal/8003@172.xx.xx.3 set(outside_call=true) 2016-11-04 09:01:06.317476 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [outside_call]=[true] EXECUTE sofia/internal/8003@172.xx.xx.3 export(RFC2822_DATE=Fri, 04 Nov 2016 09:01:06 +0200) 2016-11-04 09:01:06.317476 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 04 Nov 2016 09:01:06 +0200] EXECUTE sofia/internal/8003@172.xx.xx.3 set(transfer_after_bridge=4099) 2016-11-04 09:01:06.317476 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [transfer_after_bridge]=[4099] EXECUTE sofia/internal/8003@172.xx.xx.3 sleep(300) 2016-11-04 09:01:06.617569 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set uuid = ffefcfb3-be10-472d-8469-40692b7457da EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:06.617569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:06.617569 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set type = uuid-standby EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:06.617569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:06.617569 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set status = Available EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:06.617569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:06.617569 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = idle EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:06.617569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] EXECUTE sofia/internal/8003@172.xx.xx.3 set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3) 2016-11-04 09:01:06.617569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [cc_warning_tone]=[tone_stream://%(200,0,500,600,700);loops=3] EXECUTE sofia/internal/8003@172.xx.xx.3 answer() 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:3720 Activate Buggy RFC2833 Mode! 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4266 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4127 Set telephone-event payload to 101@8000 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [frf-dialed-digit:121:8000:20:0:1]/[G729:18:8000:20:8000:1] 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:2946 Set Codec sofia/internal/8003@172.xx.xx.3 G729/8000 20 ms 160 samples 8000 bits 1 channels 2016-11-04 09:01:06.617569 [DEBUG] switch_core_codec.c:111 sofia/internal/8003@172.xx.xx.3 Original read codec set to G729:18 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4479 Set telephone-event payload to 101@8000 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:4537 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf send payload to 101 recv payload to 101 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:6320 AUDIO RTP [sofia/internal/8003@172.xx.xx.3] 172.31.35.60 port 23388 -> 172.xx.xx.3 port 18436 codec: 18 ms: 20 2016-11-04 09:01:06.617569 [DEBUG] switch_rtp.c:3812 Starting timer [soft] 160 bytes per 20ms 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:6619 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf send payload to 101 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:6626 sofia/internal/8003@172.xx.xx.3 Set 2833 dtmf receive payload to 101 2016-11-04 09:01:06.617569 [DEBUG] switch_core_media.c:6649 sofia/internal/8003@172.xx.xx.3 Set rtp dtmf delay to 40 2016-11-04 09:01:06.617569 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/8003@172.xx.xx.3! 2016-11-04 09:01:06.617569 [DEBUG] switch_channel.c:3471 (sofia/internal/8003@172.xx.xx.3) Callstate Change RINGING -> EARLY 2016-11-04 09:01:06.617569 [DEBUG] mod_sofia.c:814 Local SDP sofia/internal/8003@172.xx.xx.3: v=0 o=FreeSWITCH 1478219478 1478219479 IN IP4 172.31.35.60 s=FreeSWITCH c=IN IP4 172.31.35.60 t=0 0 m=audio 23388 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1183 bytes to udp/[172.xx.xx.3]:5060 at 09:01:06.627947: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A23191E From: ;tag=2E56AF64-2516 To: ;tag=80540NSm23ZHN Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE 2016-11-04 09:01:06.617569 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/8003@172.xx.xx.3] has been answered Require: timer Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Session-Expires: 1800;refresher=uac Content-Type: application/sdp Content-Disposition: session Content-Length: 243 Remote-Party-ID: "4099" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1478219478 1478219479 IN IP4 172.31.35.60 s=FreeSWITCH c=IN IP4 172.31.35.60 t=0 0 m=audio 23388 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2016-11-04 09:01:06.617569 [DEBUG] switch_channel.c:3770 (sofia/internal/8003@172.xx.xx.3) Callstate Change EARLY -> ACTIVE 2016-11-04 09:01:06.617569 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [completed][200] EXECUTE sofia/internal/8003@172.xx.xx.3 playback(local_stream://moh) 2016-11-04 09:01:06.617569 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz 2016-11-04 09:01:06.617569 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms recv 389 bytes from udp/[172.xx.xx.3]:65516 at 09:01:06.637041: ------------------------------------------------------------------------ ACK sip:4099@172.31.35.60:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A241C3B From: ;tag=2E56AF64-2516 To: ;tag=80540NSm23ZHN Date: Fri, 04 Nov 2016 06:53:00 GMT Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 Max-Forwards: 70 CSeq: 101 ACK Allow-Events: telephone-event Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:06.637471 [DEBUG] sofia.c:6858 Channel sofia/internal/8003@172.xx.xx.3 entering state [ready][200] 2016-11-04 09:01:06.637471 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc180591a8 0x7efc180591a8 2016-11-04 09:01:06.637471 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc180591a8 0x7efc180591a8 2016-11-04 09:01:06.857459 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed. 2016-11-04 09:01:17.737477 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = waiting 2016-11-04 09:01:24.917526 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables 2016-11-04 09:01:24.917526 [NOTICE] switch_channel.c:1104 New Channel sofia/external/0833573222 [7f749ef1-ec7d-40f9-b17f-ef1883f6f7db] 2016-11-04 09:01:24.917526 [DEBUG] mod_sofia.c:4799 (sofia/external/0833573222) State Change CS_NEW -> CS_INIT 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_INIT 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:586 (sofia/external/0833573222) State INIT 2016-11-04 09:01:24.917526 [DEBUG] mod_sofia.c:89 sofia/external/0833573222 SOFIA INIT 2016-11-04 09:01:24.917526 [DEBUG] sofia_glue.c:1257 sofia/external/0833573222 sending invite version: 1.6.7 git f0c3870 2016-04-01 13:40:07Z 64bit Local SDP: v=0 o=FreeSWITCH 1478221714 1478221715 IN IP4 172.xx.xx.85 s=FreeSWITCH c=IN IP4 172.xx.xx.85 t=0 0 m=audio 21170 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=sendrecv 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:40 sofia/external/0833573222 Standard INIT 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:48 (sofia/external/0833573222) State Change CS_INIT -> CS_ROUTING 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:586 (sofia/external/0833573222) State INIT going to sleep 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING send 997 bytes to udp/[172.xx.xx.61]:5060 at 09:01:24.932068: ------------------------------------------------------------------------ INVITE sip:0833573222@172.xx.xx.61 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKmrm75mDKv6jgK Max-Forwards: 70 From: "" ;tag=gm3j46j4pNp5g To: Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785378 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 187 X-FS-Support: update_display,send_info Remote-Party-ID: ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1478221714 1478221715 IN IP4 172.xx.xx.85 s=FreeSWITCH c=IN IP4 172.xx.xx.85 t=0 0 m=audio 21170 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 ------------------------------------------------------------------------ 2016-11-04 09:01:24.917526 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [calling][0] 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING 2016-11-04 09:01:24.917526 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING 2016-11-04 09:01:24.917526 [DEBUG] switch_ivr_originate.c:67 (sofia/external/0833573222) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_CONSUME_MEDIA 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:621 (sofia/external/0833573222) State CONSUME_MEDIA 2016-11-04 09:01:24.917526 [DEBUG] switch_core_state_machine.c:621 (sofia/external/0833573222) State CONSUME_MEDIA going to sleep recv 291 bytes from udp/[172.xx.xx.61]:5060 at 09:01:24.932603: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKmrm75mDKv6jgK From: "" ;tag=gm3j46j4pNp5g To: Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785378 INVITE User-Agent: FS Content-Length: 0 ------------------------------------------------------------------------ recv 780 bytes from udp/[172.xx.xx.61]:5060 at 09:01:24.933589: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKmrm75mDKv6jgK From: "" ;tag=gm3j46j4pNp5g To: ;tag=jcDrBKcUKeeve Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785378 INVITE User-Agent: FS Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="172.xx.xx.61", nonce="8c34bb6a-8fe3-4cd1-83c0-1008c0f9cf95", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ send 321 bytes to udp/[172.xx.xx.61]:5060 at 09:01:24.933754: ------------------------------------------------------------------------ ACK sip:0833573222@172.xx.xx.61 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKmrm75mDKv6jgK Max-Forwards: 70 From: "" ;tag=gm3j46j4pNp5g To: ;tag=jcDrBKcUKeeve Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785378 ACK Content-Length: 0 ------------------------------------------------------------------------ send 1265 bytes to udp/[172.xx.xx.61]:5060 at 09:01:24.934090: ------------------------------------------------------------------------ INVITE sip:0833573222@172.xx.xx.61 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKN1D07FypSF92e Max-Forwards: 70 From: "" ;tag=gm3j46j4pNp5g To: Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785379 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="8c34bb6a-8fe3-4cd1-83c0-1008c0f9cf95", cnonce="V1r4Cxz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61", response="89a3cb645152d7f9faa5fb08c47cfbad", qop=auth, nc=00000001 Content-Type: application/sdp Content-Disposition: session Content-Length: 187 X-FS-Support: update_display,send_info Remote-Party-ID: ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1478221714 1478221715 IN IP4 172.xx.xx.85 s=FreeSWITCH c=IN IP4 172.xx.xx.85 t=0 0 m=audio 21170 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 ------------------------------------------------------------------------ 2016-11-04 09:01:24.917526 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [calling][0] recv 291 bytes from udp/[172.xx.xx.61]:5060 at 09:01:24.934567: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKN1D07FypSF92e From: "" ;tag=gm3j46j4pNp5g To: Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785379 INVITE User-Agent: FS Content-Length: 0 ------------------------------------------------------------------------ recv 1186 bytes from udp/[172.xx.xx.61]:5060 at 09:01:26.258940: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKN1D07FypSF92e From: "" ;tag=gm3j46j4pNp5g To: ;tag=KN6gDeXygQ4ea Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785379 INVITE Contact: User-Agent: FS Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 187 X-FS-Display-Name: Outbound Call X-FS-Display-Number: sip:D0820833573222@172.xx.xx.61 X-FS-Support: update_display,send_info Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1478221402 1478221403 IN IP4 172.xx.xx.61 s=FreeSWITCH c=IN IP4 172.xx.xx.61 t=0 0 m=audio 21498 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 ------------------------------------------------------------------------ 2016-11-04 09:01:26.257556 [INFO] sofia.c:1255 sofia/external/0833573222 Update Callee ID to "Outbound Call" 2016-11-04 09:01:26.257556 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [proceeding][183] 2016-11-04 09:01:26.257556 [DEBUG] sofia.c:6868 Remote SDP: v=0 o=FreeSWITCH 1478221402 1478221403 IN IP4 172.xx.xx.61 s=FreeSWITCH c=IN IP4 172.xx.xx.61 t=0 0 m=audio 21498 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:4211 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:4266 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:2946 Set Codec sofia/external/0833573222 G729/8000 20 ms 160 samples 8000 bits 1 channels 2016-11-04 09:01:26.257556 [DEBUG] switch_core_codec.c:111 sofia/external/0833573222 Original read codec set to G729:18 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:4509 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event. 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:4537 sofia/external/0833573222 Set 2833 dtmf send payload to 101 recv payload to 101 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:6320 AUDIO RTP [sofia/external/0833573222] 172.xx.xx.85 port 21170 -> 172.xx.xx.61 port 21498 codec: 18 ms: 20 2016-11-04 09:01:26.257556 [DEBUG] switch_rtp.c:3812 Starting timer [soft] 160 bytes per 20ms 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:6619 sofia/external/0833573222 Set 2833 dtmf send payload to 101 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:6626 sofia/external/0833573222 Set 2833 dtmf receive payload to 101 2016-11-04 09:01:26.257556 [DEBUG] switch_core_media.c:6649 sofia/external/0833573222 Set rtp dtmf delay to 40 2016-11-04 09:01:26.257556 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/0833573222! 2016-11-04 09:01:26.257556 [DEBUG] switch_channel.c:3471 (sofia/external/0833573222) Callstate Change DOWN -> EARLY 2016-11-04 09:01:26.277460 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/external/0833573222] 2016-11-04 09:01:26.277460 [DEBUG] switch_ivr.c:2160 (sofia/external/0833573222) State Change CS_CONSUME_MEDIA -> CS_ROUTING 2016-11-04 09:01:26.277460 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/0833573222 to XML[0870980890@default] 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING 2016-11-04 09:01:26.277460 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:236 sofia/external/0833573222 Standard ROUTING 2016-11-04 09:01:26.277460 [INFO] mod_dialplan_xml.c:637 Processing <0870980000>->0870980890 in context default Dialplan: sofia/external/0833573222 parsing [default->unloop] continue=false Dialplan: sofia/external/0833573222 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/0833573222 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->tod_example] continue=true Dialplan: sofia/external/0833573222 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/external/0833573222 Action set(open=true) Dialplan: sofia/external/0833573222 parsing [default->holiday_example] continue=true Dialplan: sofia/external/0833573222 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/external/0833573222 parsing [default->global-intercept] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [global-intercept] destination_number(0870980890) =~ /^886$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group-intercept] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group-intercept] destination_number(0870980890) =~ /^\*8$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->intercept-ext] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [intercept-ext] destination_number(0870980890) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->redial] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [redial] destination_number(0870980890) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->global] continue=true Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${endpoint_disposition}(EARLY MEDIA) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->snom-demo-2] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-2] destination_number(0870980890) =~ /^9001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->snom-demo-1] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-1] destination_number(0870980890) =~ /^9000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(0870980890) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(0870980890) =~ /^779$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call_return] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call_return] destination_number(0870980890) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->del-group] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [del-group] destination_number(0870980890) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->add-group] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [add-group] destination_number(0870980890) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call-group-simo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-simo] destination_number(0870980890) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call-group-order] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-order] destination_number(0870980890) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->extension-intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [extension-intercom] destination_number(0870980890) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Ext] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Ext] destination_number(0870980890) =~ /^(30[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Extension] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension] destination_number(0870980890) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension_Skinny] destination_number(0870980890) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_sales] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_sales] destination_number(0870980890) =~ /^2000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_support] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_support] destination_number(0870980890) =~ /^2001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_billing] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_billing] destination_number(0870980890) =~ /^2002$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_huntgroup] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_huntgroup] destination_number(0870980890) =~ /^0870980891$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_did_to_local] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_did_to_local] destination_number(0870980890) =~ /^0870980892$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->operator] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [operator] destination_number(0870980890) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->vmain] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [vmain] destination_number(0870980890) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->sip_uri] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [sip_uri] destination_number(0870980890) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->nb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [nb_conferences] destination_number(0870980890) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->wb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [wb_conferences] destination_number(0870980890) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->uwb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [uwb_conferences] destination_number(0870980890) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(0870980890) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(0870980890) =~ /^(35\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(0870980890) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(0870980890) =~ /^0911$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(0870980890) =~ /^0912$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss] destination_number(0870980890) =~ /^0913$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ivr_demo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ivr_demo] destination_number(0870980890) =~ /^5000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->dynamic_conference] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [dynamic_conference] destination_number(0870980890) =~ /^5001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [rtp_multicast_page] destination_number(0870980890) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] destination_number(0870980890) =~ /^5900$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] destination_number(0870980890) =~ /^5901$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(0870980890) =~ /^(6000)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(0870980890) =~ /^((?!6000)60\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->wait] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [wait] destination_number(0870980890) =~ /^wait$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->fax_receive] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_receive] destination_number(0870980890) =~ /^9178$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->fax_transmit] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_transmit] destination_number(0870980890) =~ /^9179$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_180] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_180] destination_number(0870980890) =~ /^9180$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_uk_ring] destination_number(0870980890) =~ /^9181$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_music_ring] destination_number(0870980890) =~ /^9182$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(0870980890) =~ /^9183$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_music] destination_number(0870980890) =~ /^9184$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ClueCon] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ClueCon] destination_number(0870980890) =~ /^9191$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->show_info] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [show_info] destination_number(0870980890) =~ /^9192$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->video_record] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [video_record] destination_number(0870980890) =~ /^9193$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->video_playback] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [video_playback] destination_number(0870980890) =~ /^9194$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->delay_echo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [delay_echo] destination_number(0870980890) =~ /^9195$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->echo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [echo] destination_number(0870980890) =~ /^9196$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->milliwatt] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [milliwatt] destination_number(0870980890) =~ /^9197$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->tone_stream] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [tone_stream] destination_number(0870980890) =~ /^9198$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [zrtp_enrollement] destination_number(0870980890) =~ /^9787$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->hold_music] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [hold_music] destination_number(0870980890) =~ /^9664$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->laugh break] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [laugh break] destination_number(0870980890) =~ /^9386$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->101] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [101] destination_number(0870980890) =~ /^101$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->pizza_demo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [pizza_demo] destination_number(0870980890) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Time] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Time] destination_number(0870980890) =~ /^9170$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date] destination_number(0870980890) =~ /^9171$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date and Time] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date and Time] destination_number(0870980890) =~ /^9172$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->exe_on_ans] continue=false Dialplan: sofia/external/0833573222 Regex (PASS) [exe_on_ans] destination_number(0870980890) =~ /^0870980890$/ break=on-false Dialplan: sofia/external/0833573222 Action set(execute_on_answer=transfer ANSWEREDCALL XML default) Dialplan: sofia/external/0833573222 Action log(INFO Waiting 30 seconds for $1 to answer...) Dialplan: sofia/external/0833573222 Action sleep(30000) Dialplan: sofia/external/0833573222 Action log(INFO Call to $1 was not answered, taking alternative action...) Dialplan: sofia/external/0833573222 Action transfer(UNANSWEREDCALL XML default) 2016-11-04 09:01:26.277460 [INFO] switch_channel.c:3127 sofia/external/0833573222 Flipping CID from "" <0870980000> to "Outbound Call" 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:286 (sofia/external/0833573222) State Change CS_ROUTING -> CS_EXECUTE 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_EXECUTE 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE 2016-11-04 09:01:26.277460 [DEBUG] mod_sofia.c:197 sofia/external/0833573222 SOFIA EXECUTE 2016-11-04 09:01:26.277460 [DEBUG] switch_core_state_machine.c:328 sofia/external/0833573222 Standard EXECUTE EXECUTE sofia/external/0833573222 set(open=true) 2016-11-04 09:01:26.277460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [open]=[true] EXECUTE sofia/external/0833573222 set(execute_on_answer=transfer ANSWEREDCALL XML default) 2016-11-04 09:01:26.277460 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [execute_on_answer]=[transfer ANSWEREDCALL XML default] EXECUTE sofia/external/0833573222 log(INFO Waiting 30 seconds for $1 to answer...) 2016-11-04 09:01:26.277460 [INFO] mod_dptools.c:1713 Waiting 30 seconds for $1 to answer... EXECUTE sofia/external/0833573222 sleep(30000) 2016-11-04 09:01:26.297461 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed. 2016-11-04 09:01:26.957563 [DEBUG] switch_core_media.c:2386 Correcting calculated ptime value from 300 to 150 to compensate for 1 lost packet(s) 2016-11-04 09:01:27.077565 [WARNING] switch_core_media.c:2418 Asynchronous PTIME not supported, changing our end from 20 to 60 2016-11-04 09:01:27.097469 [DEBUG] switch_core_media.c:2844 Changing Codec from G729@20ms@8000hz to G729@60ms@8000hz 2016-11-04 09:01:27.137491 [DEBUG] switch_rtp.c:3690 RE-Starting timer [soft] 480 bytes per 60ms 2016-11-04 09:01:27.137491 [DEBUG] switch_core_media.c:2946 Set Codec sofia/external/0833573222 G729/8000 60 ms 480 samples 8000 bits 1 channels 2016-11-04 09:01:27.137491 [DEBUG] switch_core_codec.c:123 sofia/external/0833573222 Original read codec replaced with G729:18 recv 1147 bytes from udp/[172.xx.xx.61]:5060 at 09:01:30.094877: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKN1D07FypSF92e From: "" ;tag=gm3j46j4pNp5g To: ;tag=KN6gDeXygQ4ea Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785379 INVITE Contact: User-Agent: FS Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 187 X-FS-Display-Name: Outbound Call X-FS-Display-Number: sip:D0820833573222@172.xx.xx.61 X-FS-Support: update_display,send_info Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1478221402 1478221403 IN IP4 172.xx.xx.61 s=FreeSWITCH c=IN IP4 172.xx.xx.61 t=0 0 m=audio 21498 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 ------------------------------------------------------------------------ 2016-11-04 09:01:30.137539 [INFO] sofia.c:1244 sofia/external/0833573222 Update Caller ID to "Outbound Call" 2016-11-04 09:01:30.137539 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [completing][200] 2016-11-04 09:01:30.137539 [DEBUG] sofia.c:6865 Duplicate SDP v=0 o=FreeSWITCH 1478221402 1478221403 IN IP4 172.xx.xx.61 s=FreeSWITCH c=IN IP4 172.xx.xx.61 t=0 0 m=audio 21498 RTP/AVP 18 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 send 674 bytes to udp/[172.xx.xx.61]:5060 at 09:01:30.142336: ------------------------------------------------------------------------ ACK sip:0833573222@172.xx.xx.61:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKpa7r9aFtprZNa Max-Forwards: 70 From: "" ;tag=gm3j46j4pNp5g To: ;tag=KN6gDeXygQ4ea Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785379 ACK Contact: Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="8c34bb6a-8fe3-4cd1-83c0-1008c0f9cf95", cnonce="V1r4Cxz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61", response="89a3cb645152d7f9faa5fb08c47cfbad", qop=auth, nc=00000001 Content-Length: 0 ------------------------------------------------------------------------ recv 666 bytes from udp/[172.xx.xx.61]:5060 at 09:01:30.174255: ------------------------------------------------------------------------ INFO sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.61;rport;branch=z9hG4bKH46X1Z83c5mDg Max-Forwards: 70 From: ;tag=KN6gDeXygQ4ea To: "" ;tag=gm3j46j4pNp5g Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785388 INFO Contact: User-Agent: FS Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Content-Type: message/update_display Content-Length: 0 X-FS-Display-Name: Outbound Call X-FS-Display-Number: D0820833573222 ------------------------------------------------------------------------ 2016-11-04 09:01:30.197459 [DEBUG] sofia.c:6858 Channel sofia/external/0833573222 entering state [ready][200] 2016-11-04 09:01:30.197459 [NOTICE] sofia.c:7765 Channel [sofia/external/0833573222] has been answered EXECUTE sofia/external/0833573222 transfer(ANSWEREDCALL XML default) 2016-11-04 09:01:30.197459 [DEBUG] switch_ivr.c:2160 (sofia/external/0833573222) State Change CS_EXECUTE -> CS_ROUTING 2016-11-04 09:01:30.197459 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/0833573222 to XML[ANSWEREDCALL@default] 2016-11-04 09:01:30.197459 [DEBUG] switch_channel.c:3770 (sofia/external/0833573222) Callstate Change EARLY -> ACTIVE 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE going to sleep 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_ROUTING send 486 bytes to udp/[172.xx.xx.61]:5060 at 09:01:30.203681: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.61;rport=5060;branch=z9hG4bKH46X1Z83c5mDg From: ;tag=KN6gDeXygQ4ea To: "" ;tag=gm3j46j4pNp5g Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785388 INFO User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING 2016-11-04 09:01:30.197459 [DEBUG] mod_sofia.c:142 sofia/external/0833573222 SOFIA ROUTING 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:236 sofia/external/0833573222 Standard ROUTING 2016-11-04 09:01:30.197459 [INFO] mod_dialplan_xml.c:637 Processing Outbound Call ->ANSWEREDCALL in context default Dialplan: sofia/external/0833573222 parsing [default->unloop] continue=false Dialplan: sofia/external/0833573222 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/0833573222 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->tod_example] continue=true Dialplan: sofia/external/0833573222 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/external/0833573222 Action set(open=true) Dialplan: sofia/external/0833573222 parsing [default->holiday_example] continue=true Dialplan: sofia/external/0833573222 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/external/0833573222 parsing [default->global-intercept] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [global-intercept] destination_number(ANSWEREDCALL) =~ /^886$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group-intercept] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group-intercept] destination_number(ANSWEREDCALL) =~ /^\*8$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->intercept-ext] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [intercept-ext] destination_number(ANSWEREDCALL) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->redial] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [redial] destination_number(ANSWEREDCALL) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->global] continue=true Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${default_password}(4321) =~ /^1234$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never Dialplan: sofia/external/0833573222 Regex (FAIL) [global] ${endpoint_disposition}(ANSWER) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->snom-demo-2] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-2] destination_number(ANSWEREDCALL) =~ /^9001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->snom-demo-1] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [snom-demo-1] destination_number(ANSWEREDCALL) =~ /^9000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(ANSWEREDCALL) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->eavesdrop] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [eavesdrop] destination_number(ANSWEREDCALL) =~ /^779$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call_return] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call_return] destination_number(ANSWEREDCALL) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->del-group] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [del-group] destination_number(ANSWEREDCALL) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->add-group] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [add-group] destination_number(ANSWEREDCALL) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call-group-simo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-simo] destination_number(ANSWEREDCALL) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->call-group-order] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [call-group-order] destination_number(ANSWEREDCALL) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->extension-intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [extension-intercom] destination_number(ANSWEREDCALL) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Ext] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Ext] destination_number(ANSWEREDCALL) =~ /^(30[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Extension] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension] destination_number(ANSWEREDCALL) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Local_Extension_Skinny] destination_number(ANSWEREDCALL) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_sales] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_sales] destination_number(ANSWEREDCALL) =~ /^2000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_support] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_support] destination_number(ANSWEREDCALL) =~ /^2001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_billing] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_billing] destination_number(ANSWEREDCALL) =~ /^2002$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_huntgroup] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_huntgroup] destination_number(ANSWEREDCALL) =~ /^0870980891$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->group_dial_did_to_local] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [group_dial_did_to_local] destination_number(ANSWEREDCALL) =~ /^0870980892$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->operator] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [operator] destination_number(ANSWEREDCALL) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->vmain] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [vmain] destination_number(ANSWEREDCALL) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->sip_uri] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [sip_uri] destination_number(ANSWEREDCALL) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->nb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [nb_conferences] destination_number(ANSWEREDCALL) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->wb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [wb_conferences] destination_number(ANSWEREDCALL) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->uwb_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [uwb_conferences] destination_number(ANSWEREDCALL) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(ANSWEREDCALL) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [cdquality_conferences] destination_number(ANSWEREDCALL) =~ /^(35\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(ANSWEREDCALL) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(ANSWEREDCALL) =~ /^0911$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss_intercom] destination_number(ANSWEREDCALL) =~ /^0912$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->mad_boss] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [mad_boss] destination_number(ANSWEREDCALL) =~ /^0913$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ivr_demo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ivr_demo] destination_number(ANSWEREDCALL) =~ /^5000$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->dynamic_conference] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [dynamic_conference] destination_number(ANSWEREDCALL) =~ /^5001$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [rtp_multicast_page] destination_number(ANSWEREDCALL) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] destination_number(ANSWEREDCALL) =~ /^5900$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] destination_number(ANSWEREDCALL) =~ /^5901$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(ANSWEREDCALL) =~ /^(6000)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->valet_park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [valet_park] destination_number(ANSWEREDCALL) =~ /^((?!6000)60\d{2})$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->park] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [park] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->unpark] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [unpark] source(src/switch_ivr_originate.c) =~ /mod_sofia/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->wait] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [wait] destination_number(ANSWEREDCALL) =~ /^wait$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->fax_receive] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_receive] destination_number(ANSWEREDCALL) =~ /^9178$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->fax_transmit] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [fax_transmit] destination_number(ANSWEREDCALL) =~ /^9179$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_180] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_180] destination_number(ANSWEREDCALL) =~ /^9180$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_uk_ring] destination_number(ANSWEREDCALL) =~ /^9181$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_183_music_ring] destination_number(ANSWEREDCALL) =~ /^9182$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(ANSWEREDCALL) =~ /^9183$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ringback_post_answer_music] destination_number(ANSWEREDCALL) =~ /^9184$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->ClueCon] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [ClueCon] destination_number(ANSWEREDCALL) =~ /^9191$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->show_info] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [show_info] destination_number(ANSWEREDCALL) =~ /^9192$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->video_record] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [video_record] destination_number(ANSWEREDCALL) =~ /^9193$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->video_playback] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [video_playback] destination_number(ANSWEREDCALL) =~ /^9194$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->delay_echo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [delay_echo] destination_number(ANSWEREDCALL) =~ /^9195$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->echo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [echo] destination_number(ANSWEREDCALL) =~ /^9196$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->milliwatt] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [milliwatt] destination_number(ANSWEREDCALL) =~ /^9197$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->tone_stream] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [tone_stream] destination_number(ANSWEREDCALL) =~ /^9198$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [zrtp_enrollement] destination_number(ANSWEREDCALL) =~ /^9787$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->hold_music] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [hold_music] destination_number(ANSWEREDCALL) =~ /^9664$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->laugh break] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [laugh break] destination_number(ANSWEREDCALL) =~ /^9386$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->101] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [101] destination_number(ANSWEREDCALL) =~ /^101$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->pizza_demo] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [pizza_demo] destination_number(ANSWEREDCALL) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Time] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Time] destination_number(ANSWEREDCALL) =~ /^9170$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date] destination_number(ANSWEREDCALL) =~ /^9171$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->Talking Clock Date and Time] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [Talking Clock Date and Time] destination_number(ANSWEREDCALL) =~ /^9172$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->exe_on_ans] continue=false Dialplan: sofia/external/0833573222 Regex (FAIL) [exe_on_ans] destination_number(ANSWEREDCALL) =~ /^0870980890$/ break=on-false Dialplan: sofia/external/0833573222 parsing [default->nb_conferences_answered] continue=false Dialplan: sofia/external/0833573222 Regex (PASS) [nb_conferences_answered] destination_number(ANSWEREDCALL) =~ /^ANSWEREDCALL$/ break=on-false Dialplan: sofia/external/0833573222 Action answer() Dialplan: sofia/external/0833573222 Action set(hangup_after_bridge=true) Dialplan: sofia/external/0833573222 Action set(continue_on_fail=true) Dialplan: sofia/external/0833573222 Action callcenter(agent8003@default) 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:286 (sofia/external/0833573222) State Change CS_ROUTING -> CS_EXECUTE 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:602 (sofia/external/0833573222) State ROUTING going to sleep 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_EXECUTE 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE 2016-11-04 09:01:30.197459 [DEBUG] mod_sofia.c:197 sofia/external/0833573222 SOFIA EXECUTE 2016-11-04 09:01:30.197459 [DEBUG] switch_core_state_machine.c:328 sofia/external/0833573222 Standard EXECUTE EXECUTE sofia/external/0833573222 set(open=true) 2016-11-04 09:01:30.197459 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [open]=[true] EXECUTE sofia/external/0833573222 answer() EXECUTE sofia/external/0833573222 set(hangup_after_bridge=true) 2016-11-04 09:01:30.197459 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [hangup_after_bridge]=[true] EXECUTE sofia/external/0833573222 set(continue_on_fail=true) 2016-11-04 09:01:30.197459 [DEBUG] mod_dptools.c:1519 SET sofia/external/0833573222 [continue_on_fail]=[true] EXECUTE sofia/external/0833573222 callcenter(agent8003@default) 2016-11-04 09:01:30.197459 [DEBUG] mod_callcenter.c:2731 Member Outbound Call joining queue agent8003@default 2016-11-04 09:01:30.197459 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz 2016-11-04 09:01:30.197459 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 60ms 2016-11-04 09:01:30.197459 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = Receiving 2016-11-04 09:01:30.197459 [DEBUG] mod_callcenter.c:1236 Updated tier: Agent 8003 in Queue agent8003@default set state = Active Inbound 2016-11-04 09:01:30.197459 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = In a queue call 2016-11-04 09:01:30.217462 [DEBUG] switch_ivr.c:623 sofia/internal/8003@172.xx.xx.3 Command Execute playback(tone_stream://%(200,0,500,600,700);loops=3) EXECUTE sofia/internal/8003@172.xx.xx.3 playback(tone_stream://%(200,0,500,600,700);loops=3) 2016-11-04 09:01:30.217462 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms 2016-11-04 09:01:30.217462 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/external/0833573222 2016-11-04 09:01:30.217462 [DEBUG] mod_callcenter.c:1776 Agent 8003 answered "Outbound Call" from queue agent8003@default (Recorded) 2016-11-04 09:01:30.217462 [DEBUG] switch_ivr_bridge.c:2010 (sofia/external/0833573222) State Change CS_EXECUTE -> CS_HIBERNATE 2016-11-04 09:01:30.217462 [DEBUG] switch_ivr_bridge.c:2012 (sofia/internal/8003@172.xx.xx.3) State Change CS_EXECUTE -> CS_HIBERNATE 2016-11-04 09:01:30.237495 [DEBUG] switch_ivr_play_say.c:1910 done playing file tone_stream://%(200,0,500,600,700);loops=3 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_async.c:1496 No silence detection configured; assuming start of speech 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_play_say.c:1910 done playing file local_stream://moh 2016-11-04 09:01:30.257460 [DEBUG] mod_callcenter.c:2887 Member Outbound Call is answered by an agent in queue agent8003@default 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:609 (sofia/external/0833573222) State EXECUTE going to sleep 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:624 (sofia/external/0833573222) State HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] mod_sofia.c:179 sofia/external/0833573222 SOFIA HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:964 (sofia/external/0833573222) State Change CS_HIBERNATE -> CS_RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:624 (sofia/external/0833573222) State HIBERNATE going to sleep 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:605 (sofia/external/0833573222) State RESET 2016-11-04 09:01:30.257460 [DEBUG] mod_sofia.c:160 sofia/external/0833573222 SOFIA RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:949 sofia/external/0833573222 CUSTOM RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:956 (sofia/external/0833573222) State Change CS_RESET -> CS_SOFT_EXECUTE 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:605 (sofia/external/0833573222) State RESET going to sleep 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_SOFT_EXECUTE 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:615 (sofia/external/0833573222) State SOFT_EXECUTE 2016-11-04 09:01:30.257460 [DEBUG] mod_sofia.c:634 SOFIA SOFT_EXECUTE 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:974 sofia/external/0833573222 CUSTOM SOFT_EXECUTE 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_play_say.c:1910 done playing file local_stream://moh 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE going to sleep 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/8003@172.xx.xx.3) State HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] mod_sofia.c:179 sofia/internal/8003@172.xx.xx.3 SOFIA HIBERNATE 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:964 (sofia/internal/8003@172.xx.xx.3) State Change CS_HIBERNATE -> CS_RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/8003@172.xx.xx.3) State HIBERNATE going to sleep 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:605 (sofia/internal/8003@172.xx.xx.3) State RESET 2016-11-04 09:01:30.257460 [DEBUG] mod_sofia.c:160 sofia/internal/8003@172.xx.xx.3 SOFIA RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_ivr_bridge.c:949 sofia/internal/8003@172.xx.xx.3 CUSTOM RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:188 sofia/internal/8003@172.xx.xx.3 Standard RESET 2016-11-04 09:01:30.257460 [DEBUG] switch_core_state_machine.c:605 (sofia/internal/8003@172.xx.xx.3) State RESET going to sleep 2016-11-04 09:01:30.277462 [DEBUG] switch_ivr_bridge.c:1006 (sofia/internal/8003@172.xx.xx.3) State Change CS_RESET -> CS_SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] switch_core_state_machine.c:615 (sofia/internal/8003@172.xx.xx.3) State SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] mod_sofia.c:634 SOFIA SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] switch_ivr_bridge.c:974 sofia/internal/8003@172.xx.xx.3 CUSTOM SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] switch_core_state_machine.c:400 sofia/internal/8003@172.xx.xx.3 Standard SOFT_EXECUTE 2016-11-04 09:01:30.277462 [DEBUG] switch_core_state_machine.c:615 (sofia/internal/8003@172.xx.xx.3) State SOFT_EXECUTE going to sleep 2016-11-04 09:01:30.297486 [DEBUG] switch_ivr_bridge.c:1489 (sofia/internal/8003@172.xx.xx.3) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_CONSUME_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] switch_ivr_bridge.c:1594 (sofia/internal/8003@172.xx.xx.3) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/8003@172.xx.xx.3) State CONSUME_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] switch_ivr_bridge.c:913 sofia/internal/8003@172.xx.xx.3 CUSTOM HOLD 2016-11-04 09:01:30.297486 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/8003@172.xx.xx.3) State CONSUME_MEDIA going to sleep 2016-11-04 09:01:30.297486 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXCHANGE_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/8003@172.xx.xx.3) State EXCHANGE_MEDIA 2016-11-04 09:01:30.297486 [DEBUG] mod_sofia.c:628 SOFIA EXCHANGE_MEDIA 2016-11-04 09:01:30.297486 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc18059128 0x7efc18059128 2016-11-04 09:01:30.297486 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc18059128 0x7efc18059128 2016-11-04 09:01:30.297486 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc18059128 0x7efc18059130 2016-11-04 09:01:30.297486 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc18059128 0x7efc18059130 2016-11-04 09:01:30.297486 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 960 bytes to accommodate 320->960 send 987 bytes to udp/[172.xx.xx.61]:5060 at 09:01:30.321326: ------------------------------------------------------------------------ INFO sip:0833573222@172.xx.xx.61:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.85;rport;branch=z9hG4bKQK0HB6ZXK1N8N Max-Forwards: 70 From: "" ;tag=gm3j46j4pNp5g To: ;tag=KN6gDeXygQ4ea Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785380 INFO Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Proxy-Authorization: Digest username="Enav8Pre", realm="172.xx.xx.61", nonce="8c34bb6a-8fe3-4cd1-83c0-1008c0f9cf95", cnonce="V1r4Cxz/EjWAOwBQVosP+A", algorithm=MD5, uri="sip:0833573222@172.xx.xx.61:5060;transport=udp", response="3373021804fd53a94bf425cd71cbdf4e", qop=auth, nc=00000002 Content-Type: message/update_display Content-Length: 0 X-FS-Display-Name: 8003 X-FS-Display-Number: 8003 ------------------------------------------------------------------------ 2016-11-04 09:01:30.317459 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1400cab8 0x7efc1400cab8 2016-11-04 09:01:30.317459 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1400cab8 0x7efc1400cab8 recv 433 bytes from udp/[172.xx.xx.61]:5060 at 09:01:30.337160: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.85;rport=5060;branch=z9hG4bKQK0HB6ZXK1N8N From: "" ;tag=gm3j46j4pNp5g To: ;tag=KN6gDeXygQ4ea Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785380 INFO User-Agent: FS Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:30.377545 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed. 2016-11-04 09:01:30.377545 [DEBUG] switch_core_io.c:448 Setting BUG Codec G729:18 2016-11-04 09:01:30.377545 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc202c5060 0x7efc202c5068 2016-11-04 09:01:30.377545 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc202c5060 0x7efc202c5068 2016-11-04 09:01:30.377545 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc1400cad8 0x7efc1400cae0 2016-11-04 09:01:30.377545 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc1400cad8 0x7efc1400cae0 2016-11-04 09:01:30.377545 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 320 bytes to accommodate 960->320 2016-11-04 09:01:47.757473 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc1400cab8 0x7efc1400cab8 2016-11-04 09:01:47.757473 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc1400cab8 0x7efc1400cab8 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc1400cad8 0x7efc1400cae0 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc1400cad8 0x7efc1400cae0 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc1400cb18 0x7efc1400cb20 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc1400cb18 0x7efc1400cb20 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1400caf8 0x7efc1400caf8 2016-11-04 09:01:47.777485 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1400caf8 0x7efc1400caf8 2016-11-04 09:01:47.857472 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc1400caf8 0x7efc1400caf8 2016-11-04 09:01:47.857472 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc1400caf8 0x7efc1400caf8 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc1400cb18 0x7efc1400cb20 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc1400cb18 0x7efc1400cb20 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:164 DECODER LICENSE ALLOCATED--->0x7efc1400cb58 0x7efc1400cb60 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:171 DECODER CREATED------------->0x7efc1400cb58 0x7efc1400cb60 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1400cb38 0x7efc1400cb38 2016-11-04 09:01:47.897526 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1400cb38 0x7efc1400cb38 2016-11-04 09:01:48.017561 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc1400cb38 0x7efc1400cb38 2016-11-04 09:01:48.017561 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc1400cb38 0x7efc1400cb38 2016-11-04 09:01:48.017561 [INFO] mod_com_g729.c:126 ENCODER LICENSE ALLOCATED--->0x7efc1400cb78 0x7efc1400cb78 2016-11-04 09:01:48.017561 [INFO] mod_com_g729.c:133 ENCODER CREATED------------->0x7efc1400cb78 0x7efc1400cb78 2016-11-04 09:01:48.077532 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc1400cb58 0x7efc1400cb60 2016-11-04 09:01:48.077532 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc1400cb58 0x7efc1400cb60 recv 586 bytes from udp/[172.xx.xx.61]:5060 at 09:01:48.158992: ------------------------------------------------------------------------ BYE sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8 SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.61;rport;branch=z9hG4bK2Xm3ZB7ZUvFBN Max-Forwards: 70 From: ;tag=KN6gDeXygQ4ea To: "" ;tag=gm3j46j4pNp5g Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785389 BYE User-Agent: FS Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Reason: Q.850;cause=16 Content-Length: 0 P-RTP-Stat: PS=364,OS=21840,PR=293,OR=17580,PL=0,JI=0,LA=0,DU=18 ------------------------------------------------------------------------ 2016-11-04 09:01:48.197470 [NOTICE] sofia.c:988 Hangup sofia/external/0833573222 [CS_SOFT_EXECUTE] [NORMAL_CLEARING] send 485 bytes to udp/[172.xx.xx.61]:5060 at 09:01:48.202744: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.61;rport=5060;branch=z9hG4bK2Xm3ZB7ZUvFBN From: ;tag=KN6gDeXygQ4ea To: "" ;tag=gm3j46j4pNp5g Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8 CSeq: 98785389 BYE User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/external/0833573222] 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_bridge.c:701 sofia/external/0833573222 ending bridge by request from write function 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_bridge.c:780 BRIDGE THREAD DONE [sofia/internal/8003@172.xx.xx.3] 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr.c:2160 (sofia/internal/8003@172.xx.xx.3) State Change CS_EXCHANGE_MEDIA -> CS_ROUTING 2016-11-04 09:01:48.197470 [NOTICE] switch_ivr.c:2167 Transfer sofia/internal/8003@172.xx.xx.3 to XML[4099@public] 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/8003@172.xx.xx.3) State EXCHANGE_MEDIA going to sleep 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_ROUTING 2016-11-04 09:01:48.197470 [DEBUG] switch_channel.c:2249 (sofia/internal/8003@172.xx.xx.3) Callstate Change ACTIVE -> RINGING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING 2016-11-04 09:01:48.197470 [DEBUG] mod_sofia.c:142 sofia/internal/8003@172.xx.xx.3 SOFIA ROUTING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:236 sofia/internal/8003@172.xx.xx.3 Standard ROUTING 2016-11-04 09:01:48.197470 [INFO] mod_dialplan_xml.c:637 Processing Outbound Call ->4099 in context public Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->unloop] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_huntgroup] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_huntgroup] destination_number(4099) =~ /^0870980891$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->group_dial_did_to_local] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [group_dial_did_to_local] destination_number(4099) =~ /^0870980892$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->outside_call] continue=true Dialplan: sofia/internal/8003@172.xx.xx.3 Absolute Condition [outside_call] Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(outside_call=true) Dialplan: sofia/internal/8003@172.xx.xx.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->call_debug] continue=true Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_extensions] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_extensions] destination_number(4099) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(5551212)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->public_did] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [public_did] destination_number(4099) =~ /^(0870980892)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980890$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->nb_conferences] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [nb_conferences] destination_number(4099) =~ /^0870980893$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->conf11001] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (FAIL) [conf11001] destination_number(4099) =~ /^11001$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 parsing [public->UNKNOWN] continue=false Dialplan: sofia/internal/8003@172.xx.xx.3 Regex (PASS) [UNKNOWN] destination_number(4099) =~ /^(4099)$/ break=on-false Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(transfer_after_bridge=4099) Dialplan: sofia/internal/8003@172.xx.xx.3 Action sleep(300) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set uuid ${caller_id_number} '${uuid}')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set type ${caller_id_number} 'uuid-standby')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set status ${caller_id_number} 'Available')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(res=${callcenter_config(agent set state ${caller_id_number} 'idle')}) Dialplan: sofia/internal/8003@172.xx.xx.3 Action set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3) Dialplan: sofia/internal/8003@172.xx.xx.3 Action answer() Dialplan: sofia/internal/8003@172.xx.xx.3 Action playback(local_stream://moh) 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_bridge.c:1695 sofia/external/0833573222 skip receive message [UNBRIDGE] (channel is hungup already) 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:615 (sofia/external/0833573222) State SOFT_EXECUTE going to sleep 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_HANGUP 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_async.c:1312 Stop recording file /usr/local/freeswitch/recordings/2016-11-04-09-01-30.ANSWEREDCALL.D0820833573222.7f749ef1-ec7d-40f9-b17f-ef1883f6f7db.wav 2016-11-04 09:01:48.197470 [INFO] switch_channel.c:3127 sofia/internal/8003@172.xx.xx.3 Flipping CID from "Outbound Call" to "8003" <8003> 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/8003@172.xx.xx.3) State Change CS_ROUTING -> CS_EXECUTE 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/8003@172.xx.xx.3) State ROUTING going to sleep 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_EXECUTE 2016-11-04 09:01:48.197470 [DEBUG] switch_channel.c:2251 (sofia/internal/8003@172.xx.xx.3) Callstate Change RINGING -> ACTIVE 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE 2016-11-04 09:01:48.197470 [DEBUG] mod_sofia.c:197 sofia/internal/8003@172.xx.xx.3 SOFIA EXECUTE 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:328 sofia/internal/8003@172.xx.xx.3 Standard EXECUTE EXECUTE sofia/internal/8003@172.xx.xx.3 set(outside_call=true) 2016-11-04 09:01:48.197470 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [outside_call]=[true] EXECUTE sofia/internal/8003@172.xx.xx.3 export(RFC2822_DATE=Fri, 04 Nov 2016 09:01:48 +0200) 2016-11-04 09:01:48.197470 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 04 Nov 2016 09:01:48 +0200] EXECUTE sofia/internal/8003@172.xx.xx.3 set(transfer_after_bridge=4099) 2016-11-04 09:01:48.197470 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [transfer_after_bridge]=[4099] EXECUTE sofia/internal/8003@172.xx.xx.3 sleep(300) 2016-11-04 09:01:48.197470 [DEBUG] switch_ivr_async.c:1376 Channel is hung up 2016-11-04 09:01:48.197470 [DEBUG] switch_core_media_bug.c:1120 Removing BUG from sofia/external/0833573222 2016-11-04 09:01:48.197470 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc202c5060 0x7efc202c5068 2016-11-04 09:01:48.197470 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc202c5060 0x7efc202c5068 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:809 (sofia/external/0833573222) Callstate Change ACTIVE -> HANGUP 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:811 (sofia/external/0833573222) State HANGUP 2016-11-04 09:01:48.197470 [DEBUG] mod_sofia.c:437 Channel sofia/external/0833573222 hanging up, cause: NORMAL_CLEARING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:60 sofia/external/0833573222 Standard HANGUP, cause: NORMAL_CLEARING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:811 (sofia/external/0833573222) State HANGUP going to sleep 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:578 (sofia/external/0833573222) State Change CS_HANGUP -> CS_REPORTING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:543 (sofia/external/0833573222) Running State Change CS_REPORTING 2016-11-04 09:01:48.197470 [DEBUG] switch_core_state_machine.c:897 (sofia/external/0833573222) State REPORTING 2016-11-04 09:01:48.197470 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_both (start_stamp, CallId, TEST_id, end_stamp) VALUES ('2016-11-04 09:01:24', '7f749ef1-ec7d-40f9-b17f-ef1883f6f7db', 'Enav8Pre@172.xx.xx.61', '2016-11-04 09:01:48') 2016-11-04 09:01:48.217481 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = Waiting 2016-11-04 09:01:48.417470 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_a_leg (start_stamp, TelNumberFull, CallId, sip_endpoint_disposition, orig_id, CallerID, CODEC, sip_current_application, IP, term_id, ClientId, end_stamp) VALUES ('2016-11-04 09:01:24', '0833573222', '7f749ef1-ec7d-40f9-b17f-ef1883f6f7db', 'ANSWER', '7f749ef1-ec7d-40f9-b17f-ef1883f6f7db', 'Enav8Pre', 'G729', 'callcenter', '172.xx.xx.61', '575aae37-1cff-1235-3b80-0050568b0ff8', '7f749ef1-ec7d-40f9-b17f-ef1883f6f7db', '2016-11-04 09:01:48') 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:174 sofia/external/0833573222 Standard REPORTING, cause: NORMAL_CLEARING 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:897 (sofia/external/0833573222) State REPORTING going to sleep 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:569 (sofia/external/0833573222) State Change CS_REPORTING -> CS_DESTROY 2016-11-04 09:01:48.497495 [DEBUG] switch_core_session.c:1646 Session 101 (sofia/external/0833573222) Locked, Waiting on external entities 2016-11-04 09:01:48.497495 [NOTICE] switch_core_session.c:1664 Session 101 (sofia/external/0833573222) Ended 2016-11-04 09:01:48.497495 [NOTICE] switch_core_session.c:1668 Close Channel sofia/external/0833573222 [CS_DESTROY] 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:700 (sofia/external/0833573222) Running State Change CS_DESTROY 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:710 (sofia/external/0833573222) State DESTROY 2016-11-04 09:01:48.497495 [DEBUG] mod_sofia.c:342 sofia/external/0833573222 SOFIA DESTROY 2016-11-04 09:01:48.497495 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc1400cb78 0x7efc1400cb78 2016-11-04 09:01:48.497495 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc1400cb78 0x7efc1400cb78 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:181 sofia/external/0833573222 Standard DESTROY 2016-11-04 09:01:48.497495 [DEBUG] switch_core_state_machine.c:710 (sofia/external/0833573222) State DESTROY going to sleep 2016-11-04 09:01:48.497495 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set uuid = ffefcfb3-be10-472d-8469-40692b7457da EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:48.497495 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:48.497495 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set type = uuid-standby EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:48.497495 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:48.497495 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set status = Available EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:48.497495 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] 2016-11-04 09:01:48.497495 [DEBUG] mod_callcenter.c:1115 Updated Agent 8003 set state = idle EXECUTE sofia/internal/8003@172.xx.xx.3 set(res=+OK ) 2016-11-04 09:01:48.497495 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [res]=[+OK ] EXECUTE sofia/internal/8003@172.xx.xx.3 set(cc_warning_tone=tone_stream://%(200,0,500,600,700);loops=3) 2016-11-04 09:01:48.497495 [DEBUG] mod_dptools.c:1519 SET sofia/internal/8003@172.xx.xx.3 [cc_warning_tone]=[tone_stream://%(200,0,500,600,700);loops=3] EXECUTE sofia/internal/8003@172.xx.xx.3 answer() EXECUTE sofia/internal/8003@172.xx.xx.3 playback(local_stream://moh) 2016-11-04 09:01:48.497495 [DEBUG] mod_local_stream.c:843 Opening Stream [moh/8000] 8000hz 2016-11-04 09:01:48.497495 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms recv 512 bytes from udp/[172.xx.xx.3]:65516 at 09:01:54.037344: ------------------------------------------------------------------------ BYE sip:4099@172.31.35.60:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A291F7A From: ;tag=2E56AF64-2516 To: ;tag=80540NSm23ZHN Date: Fri, 04 Nov 2016 06:53:00 GMT Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 User-Agent: Cisco-SIPGateway/IOS-12.x Max-Forwards: 70 Timestamp: 1478242428 CSeq: 102 BYE Reason: Q.850;cause=16 P-RTP-Stat: PS=2361,OS=47220,PR=2322,OR=46440,PL=0,JI=0,LA=0,DU=47 Content-Length: 0 ------------------------------------------------------------------------ send 379 bytes to udp/[172.xx.xx.3]:5060 at 09:01:54.037615: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A291F7A From: ;tag=2E56AF64-2516 To: ;tag=80540NSm23ZHN Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 CSeq: 102 BYE Timestamp: 1478242428 0.000032 User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Content-Length: 0 ------------------------------------------------------------------------ 2016-11-04 09:01:54.037485 [NOTICE] sofia.c:988 Hangup sofia/internal/8003@172.xx.xx.3 [CS_EXECUTE] [NORMAL_CLEARING] 2016-11-04 09:01:54.037485 [DEBUG] switch_ivr_play_say.c:1910 done playing file local_stream://moh send 553 bytes to udp/[172.xx.xx.3]:5060 at 09:01:54.046712: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.xx.xx.3:5060;branch=z9hG4bK109A291F7A From: ;tag=2E56AF64-2516 To: ;tag=80540NSm23ZHN Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3 CSeq: 102 BYE User-Agent: FreeSWITCH-mod_sofia/1.6.7+git~20160401T134007Z~f0c3870be3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 P-RTP-Stat: PS=364,OS=21840,PR=293,OR=17580,PL=0,JI=0,LA=0,DU=18 ------------------------------------------------------------------------ 2016-11-04 09:01:54.037485 [DEBUG] switch_core_session.c:2796 sofia/internal/8003@172.xx.xx.3 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/8003@172.xx.xx.3) State EXECUTE going to sleep 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_HANGUP 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/8003@172.xx.xx.3) Callstate Change ACTIVE -> HANGUP 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/8003@172.xx.xx.3) State HANGUP 2016-11-04 09:01:54.037485 [DEBUG] mod_sofia.c:431 sofia/internal/8003@172.xx.xx.3 Overriding SIP cause 480 with 200 from the other leg 2016-11-04 09:01:54.037485 [DEBUG] mod_sofia.c:437 Channel sofia/internal/8003@172.xx.xx.3 hanging up, cause: NORMAL_CLEARING 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:60 sofia/internal/8003@172.xx.xx.3 Standard HANGUP, cause: NORMAL_CLEARING 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/8003@172.xx.xx.3) State HANGUP going to sleep 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/8003@172.xx.xx.3) State Change CS_HANGUP -> CS_REPORTING 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_REPORTING 2016-11-04 09:01:54.037485 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/8003@172.xx.xx.3) State REPORTING 2016-11-04 09:01:54.037485 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_both (start_stamp, CallId, TEST_id, end_stamp) VALUES ('2016-11-04 09:01:06', 'ffefcfb3-be10-472d-8469-40692b7457da', '8003@172.xx.xx.3', '2016-11-04 09:01:54') 2016-11-04 09:01:54.075486 [DEBUG] mod_odbc_cdr.c:309 sql INSERT INTO cdr_table_a_leg (start_stamp, TelNumberFull, TelNumber, CallId, sip_endpoint_disposition, orig_id, CallerID, CODEC, sip_current_application, directGateway, IPInternal, IP, term_id, ClientId, end_stamp) VALUES ('2016-11-04 09:01:06', '4099', '4099', 'ffefcfb3-be10-472d-8469-40692b7457da', 'ANSWER', 'ffefcfb3-be10-472d-8469-40692b7457da', '8003', 'G729', 'playback', '172.31.35.60', '172.xx.xx.3', '172.xx.xx.3', '2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3', 'ffefcfb3-be10-472d-8469-40692b7457da', '2016-11-04 09:01:54') 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:174 sofia/internal/8003@172.xx.xx.3 Standard REPORTING, cause: NORMAL_CLEARING 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/8003@172.xx.xx.3) State REPORTING going to sleep 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/8003@172.xx.xx.3) State Change CS_REPORTING -> CS_DESTROY 2016-11-04 09:01:54.075486 [DEBUG] switch_core_session.c:1646 Session 100 (sofia/internal/8003@172.xx.xx.3) Locked, Waiting on external entities 2016-11-04 09:01:54.075486 [NOTICE] switch_core_session.c:1664 Session 100 (sofia/internal/8003@172.xx.xx.3) Ended 2016-11-04 09:01:54.075486 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/8003@172.xx.xx.3 [CS_DESTROY] 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/8003@172.xx.xx.3) Running State Change CS_DESTROY 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/8003@172.xx.xx.3) State DESTROY 2016-11-04 09:01:54.075486 [DEBUG] mod_sofia.c:342 sofia/internal/8003@172.xx.xx.3 SOFIA DESTROY 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc18059128 0x7efc18059128 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc18059128 0x7efc18059128 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:95 DECODER DESTROYED----------->0x7efc18059128 0x7efc18059130 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:98 DECODER LICENSE DEALLOCATED->0x7efc18059128 0x7efc18059130 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:84 ENCODER DESTROYED----------->0x7efc180591a8 0x7efc180591a8 2016-11-04 09:01:54.075486 [INFO] mod_com_g729.c:87 ENCODER LICENSE DEALLOCATED->0x7efc180591a8 0x7efc180591a8 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:181 sofia/internal/8003@172.xx.xx.3 Standard DESTROY 2016-11-04 09:01:54.075486 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/8003@172.xx.xx.3) State DESTROY going to sleep freeswitch@GCNDialer>