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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>
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: <sip:8003@172.xx.xx.3:5060>
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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>
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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>;tag=80540NSm23ZHN
Call-ID: 2906F641-A19211E6-BC7FC7B1-C40D3FF0@172.xx.xx.3
CSeq: 101 INVITE
Contact: <sip:4099@172.31.35.60:5060;transport=udp>
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" <sip:4099@172.31.35.60>;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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>;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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785378 INVITE
Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
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: <sip:0870980000@172.xx.xx.61>;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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>
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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785379 INVITE
Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
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: <sip:0870980000@172.xx.xx.61>;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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>
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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785379 INVITE
Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
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" <sip:D0820833573222@172.xx.xx.61>;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" <sip:D0820833573222@172.xx.xx.61>
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" <D0820833573222>
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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785379 INVITE
Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
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" <sip:D0820833573222@172.xx.xx.61>;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" <sip:D0820833573222@172.xx.xx.61>
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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785379 ACK
Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
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: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
To: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785388 INFO
Contact: <sip:0833573222@172.xx.xx.61:5060;transport=udp>
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: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
To: "" <sip:Enav8Pre@172.xx.xx.61>;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 <D0820833573222>->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 <D0820833573222> 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" <D0820833573222> 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 <D0820833573222> 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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
Call-ID: 575aae37-1cff-1235-3b80-0050568b0ff8
CSeq: 98785380 INFO
Contact: <sip:gw+Enav8@172.xx.xx.85:5060;transport=udp;gw=Enav8>
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: "" <sip:Enav8Pre@172.xx.xx.61>;tag=gm3j46j4pNp5g
To: <sip:0833573222@172.xx.xx.61>;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: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
To: "" <sip:Enav8Pre@172.xx.xx.61>;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: <sip:0833573222@172.xx.xx.61>;tag=KN6gDeXygQ4ea
To: "" <sip:Enav8Pre@172.xx.xx.61>;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 <D0820833573222>->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" <D0820833573222> 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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>;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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>;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: <sip:8003@172.xx.xx.3>;tag=2E56AF64-2516
To: <sip:4099@172.31.35.60>;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>