Version 4.2.4, Commit: 71f95776fc776dd79040278d8c0e6a09bfe889bc
Switch Version 1.6.19 (64bit), Debian 3.16.43-2+deb8u5 (2017-09-19) x86_64 GNU/Linux
I am having an issue with Ring Groups in a newer installation of Fusionpbx and verified on 2 separate installations/machines that were setup at the same time using the install script.
Basically what is happening, is the varying Ring Groups are not respecting the call timeouts that are set on the destinations.
Expected function would be call come in from PSTN, to SBC, and then to PBX... and hits public dialplan where it is routed to the ring group for the domain(s).
Call attempts to reach destinations and respects each destinations timeout individually but doesnt hunt through all of the destinations like a find me feature.
The captured call, was to a ring group setup using Rollover Strategy, and has 2 extensions listed as destinations (101 and 102, both active and registered) with orders of 0 and 5, and both are set to timeout after 30 seconds.
Timeout destination is set to voicemail for the 101 extension. Account code and Context are set (properly), and ringback set to us-ring (basically the defaults when creating a group).
What happens instead, is the session gets a call_timeout=300 set when it goes into app.lua ring_group and that overrides the call_timeout=30 (I belive is affecting but maybe wrong?).
I have tried commenting this out and it cause it to respect the timeouts on the destinations, but it had to go through both destinations first before timing out.
I can see the calls are also being transfered to both destinations in sequence... and both must timeout before it goes to the timeout destination, which is completely different behavior from my older Fusionpbx installations.
Enterprise strategy does work(ish), and Simultaneous strategy appears to function ok... really just Random, Rollover, and Sequence that are having a problem.
67.X.X.237 = CPE (SPA122 running 1.2.1)
X.X.X.69 = SBC (Freeswitch Version 1.2.24+git~20150504T151740Z~da04da87df~64bit (git da04da8 2015-05-04 15:17:40Z 64bit)
X.X.X.67 = PBX (At very top)
Absolutely Zero NAT involved on the CPE, the PBX, or the SBC.
------------------------------------------------------------------------
recv 460 bytes from udp/[67.X.X.237]:5060 at 21:45:33.125064:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-70283988;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 7 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 657 bytes to udp/[67.X.X.237]:5060 at 21:45:33.125388:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-70283988;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=ypK5e1g79v5ja
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 7 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 458 bytes from udp/[67.X.X.237]:5061 at 21:45:33.327505:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-497b416d;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 7 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 655 bytes to udp/[67.X.X.237]:5061 at 21:45:33.327782:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-497b416d;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=ZZcygv1a75U5N
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 7 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
send 543 bytes to udp/[X.X.X.69]:5080 at 21:45:40.498449:
------------------------------------------------------------------------
OPTIONS sip:sbc.myvoipdomain.com:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.67:5080;rport;branch=z9hG4bK1gDtp3Q288rUm
Max-Forwards: 70
From: <sip:sbc.myvoipdomain.com:5080>;tag=3620N0ZvS6BSH
To: <sip:sbc.myvoipdomain.com:5080>
Call-ID: 64e47dc6-9d2e-1236-bd8b-626338373834
CSeq: 119380027 OPTIONS
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[X.X.X.69]:5080 at 21:45:40.499244:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.67:5080;rport=5080;branch=z9hG4bK1gDtp3Q288rUm
From: <sip:sbc.myvoipdomain.com:5080>;tag=3620N0ZvS6BSH
To: <sip:sbc.myvoipdomain.com:5080>;tag=tc4yDU20Qy1KF
Call-ID: 64e47dc6-9d2e-1236-bd8b-626338373834
CSeq: 119380027 OPTIONS
Contact: <sip:X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 1190 bytes from udp/[X.X.X.69]:5080 at 21:45:44.431191:
------------------------------------------------------------------------
INVITE sip:5203810101@X.X.X.67:5080 SIP/2.0
Via: SIP/2.0/UDP X.X.X.69:5080;rport;branch=z9hG4bKp1Qv85aX6m6KD
Max-Forwards: 70
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 INVITE
Contact: <sip:mod_sofia@X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 256
X-FS-Support: update_display,send_info
P-Asserted-Identity: "5207050202" <sip:5207050202@X.X.X.69>
v=0
o=FreeSWITCH 2424207514 2424207515 IN IP4 X.X.X.69
s=FreeSWITCH
c=IN IP4 X.X.X.69
t=0 0
m=audio 23212 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=rtcp:11051
------------------------------------------------------------------------
send 316 bytes to udp/[X.X.X.69]:5080 at 21:45:44.431683:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKp1Qv85aX6m6KD
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 INVITE
User-Agent: FreeSWITCH
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:45:44.428980 [NOTICE] switch_channel.c:1104 New Channel sofia/external/5207050202@X.X.X.69 [e79c8124-9fc7-4144-8459-1f547f7930ed]
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_NEW (Cur 1 Tot 4868)
2018-03-07 21:45:44.428980 [DEBUG] sofia.c:9873 sofia/external/5207050202@X.X.X.69 receiving invite from X.X.X.69:5080 version: 1.6.19 -36-7a77e0b 64bit
2018-03-07 21:45:44.428980 [DEBUG] sofia.c:7084 Channel sofia/external/5207050202@X.X.X.69 entering state [received][100]
2018-03-07 21:45:44.428980 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=FreeSWITCH 2424207514 2424207515 IN IP4 X.X.X.69
s=FreeSWITCH
c=IN IP4 X.X.X.69
t=0 0
m=audio 23212 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=rtcp:11051
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/5207050202@X.X.X.69 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-03-07 21:45:44.428980 [DEBUG] switch_core_codec.c:111 sofia/external/5207050202@X.X.X.69 Original read codec set to PCMU:0
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-03-07 21:45:44.428980 [DEBUG] switch_core_media.c:4767 sofia/external/5207050202@X.X.X.69 Set 2833 dtmf send payload to 101 recv payload to 101
2018-03-07 21:45:44.428980 [DEBUG] sofia.c:7507 (sofia/external/5207050202@X.X.X.69) State Change CS_NEW -> CS_INIT
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:603 (sofia/external/5207050202@X.X.X.69) State NEW
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_INIT (Cur 1 Tot 4868)
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:627 (sofia/external/5207050202@X.X.X.69) State INIT
2018-03-07 21:45:44.428980 [DEBUG] mod_sofia.c:90 sofia/external/5207050202@X.X.X.69 SOFIA INIT
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:40 sofia/external/5207050202@X.X.X.69 Standard INIT
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:48 (sofia/external/5207050202@X.X.X.69) State Change CS_INIT -> CS_ROUTING
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:627 (sofia/external/5207050202@X.X.X.69) State INIT going to sleep
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_ROUTING (Cur 1 Tot 4868)
2018-03-07 21:45:44.428980 [DEBUG] switch_channel.c:2249 (sofia/external/5207050202@X.X.X.69) Callstate Change DOWN -> RINGING
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5207050202@X.X.X.69) State ROUTING
2018-03-07 21:45:44.428980 [DEBUG] mod_sofia.c:143 sofia/external/5207050202@X.X.X.69 SOFIA ROUTING
2018-03-07 21:45:44.428980 [DEBUG] switch_core_state_machine.c:236 sofia/external/5207050202@X.X.X.69 Standard ROUTING
2018-03-07 21:45:44.428980 [INFO] mod_dialplan_xml.c:637 Processing 5207050202 <5207050202>->5203810101 in context public
2018-03-07 21:45:44.488387 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.508387 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [public->5203810101] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [5203810101] destination_number(5203810101) =~ /^(5203810101)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/5207050202@X.X.X.69 set(call_direction=inbound)
2018-03-07 21:45:44.508387 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [call_direction]=[inbound]
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(domain_uuid=52958648-0cdf-46da-8700-adf7814389c3) INLINE
EXECUTE sofia/external/5207050202@X.X.X.69 set(domain_uuid=52958648-0cdf-46da-8700-adf7814389c3)
2018-03-07 21:45:44.508387 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [domain_uuid]=[52958648-0cdf-46da-8700-adf7814389c3]
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(domain_name=64.myvoipdomain.com) INLINE
EXECUTE sofia/external/5207050202@X.X.X.69 set(domain_name=64.myvoipdomain.com)
2018-03-07 21:45:44.508387 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [domain_name]=[64.myvoipdomain.com]
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(accountcode=64)
Dialplan: sofia/external/5207050202@X.X.X.69 Action transfer(7401 XML 64.myvoipdomain.com)
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5207050202@X.X.X.69) State Change CS_ROUTING -> CS_EXECUTE
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5207050202@X.X.X.69) State ROUTING going to sleep
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_EXECUTE (Cur 1 Tot 4868)
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5207050202@X.X.X.69) State EXECUTE
2018-03-07 21:45:44.508387 [DEBUG] mod_sofia.c:198 sofia/external/5207050202@X.X.X.69 SOFIA EXECUTE
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:328 sofia/external/5207050202@X.X.X.69 Standard EXECUTE
EXECUTE sofia/external/5207050202@X.X.X.69 set(accountcode=64)
2018-03-07 21:45:44.508387 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [accountcode]=[64]
EXECUTE sofia/external/5207050202@X.X.X.69 transfer(7401 XML 64.myvoipdomain.com)
2018-03-07 21:45:44.508387 [DEBUG] switch_ivr.c:2165 (sofia/external/5207050202@X.X.X.69) State Change CS_EXECUTE -> CS_ROUTING
2018-03-07 21:45:44.508387 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/5207050202@X.X.X.69 to XML[7401@64.myvoipdomain.com]
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5207050202@X.X.X.69) State EXECUTE going to sleep
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_ROUTING (Cur 1 Tot 4868)
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5207050202@X.X.X.69) State ROUTING
2018-03-07 21:45:44.508387 [DEBUG] mod_sofia.c:143 sofia/external/5207050202@X.X.X.69 SOFIA ROUTING
2018-03-07 21:45:44.508387 [DEBUG] switch_core_state_machine.c:236 sofia/external/5207050202@X.X.X.69 Standard ROUTING
2018-03-07 21:45:44.508387 [INFO] mod_dialplan_xml.c:637 Processing 5207050202 <5207050202>->7401 in context 64.myvoipdomain.com
2018-03-07 21:45:44.528382 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.548405 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->user_exists] continue=true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-03-07 21:45:44.568381 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.568381 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
EXECUTE sofia/external/5207050202@X.X.X.69 set(user_exists=false)
2018-03-07 21:45:44.568381 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [user_exists]=[false]
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->call-direction] continue=true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->variables] continue=true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->user_record] continue=true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-03-07 21:45:44.568381 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.568381 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
2018-03-07 21:45:44.568381 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.588568 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
EXECUTE sofia/external/5207050202@X.X.X.69 set(user_record=)
2018-03-07 21:45:44.588568 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [user_record]=[UNDEF]
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2018-03-07 21:45:44.588568 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.588568 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
EXECUTE sofia/external/5207050202@X.X.X.69 set(from_user_exists=false)
2018-03-07 21:45:44.588568 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [from_user_exists]=[false]
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->redial] continue=true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [redial] destination_number(7401) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/5207050202@X.X.X.69 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->speed_dial] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [speed_dial] destination_number(7401) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->sbc.myvoipdomain.com.3911] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [sbc.myvoipdomain.com.3911] destination_number(7401) =~ /^([3-9]11)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->sbc.myvoipdomain.com.7d] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [sbc.myvoipdomain.com.7d] destination_number(7401) =~ /^(\d{7})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->sbc.myvoipdomain.com.10d] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [sbc.myvoipdomain.com.10d] destination_number(7401) =~ /^(\d{10})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->sbc.myvoipdomain.com.11d] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [sbc.myvoipdomain.com.11d] destination_number(7401) =~ /^1(\d{10})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->agent_status] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [agent_status] destination_number(7401) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->agent_status_id] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [agent_status_id] destination_number(7401) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->group-intercept] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [group-intercept] destination_number(7401) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->page-extension] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [page-extension] destination_number(7401) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->eavesdrop] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [eavesdrop] destination_number(7401) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->call_privacy] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [call_privacy] destination_number(7401) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->call_return] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [call_return] destination_number(7401) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->extension_queue] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [extension_queue] destination_number(7401) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->intercept-ext] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [intercept-ext] destination_number(7401) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->intercept-ext-polycom] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [intercept-ext-polycom] destination_number(7401) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->dx] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [dx] destination_number(7401) =~ /^dx$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->att_xfer] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [att_xfer] destination_number(7401) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->extension-to-voicemail] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->send_to_voicemail] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [send_to_voicemail] destination_number(7401) =~ /^\*99(\d{2,10})$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->vmain] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [vmain] destination_number(7401) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->xfer_vm] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [xfer_vm] destination_number(7401) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->is_transfer] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [is_transfer] destination_number(7401) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->vmain_user] continue=false
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (FAIL) [vmain_user] destination_number(7401) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 parsing [64.myvoipdomain.com->Group1] continue=
Dialplan: sofia/external/5207050202@X.X.X.69 Regex (PASS) [Group1] destination_number(7401) =~ /^7401$/ break=on-false
Dialplan: sofia/external/5207050202@X.X.X.69 Action set(ring_group_uuid=264e547d-425a-4655-96a4-e05fa08c85eb)
Dialplan: sofia/external/5207050202@X.X.X.69 Action lua(app.lua ring_groups)
2018-03-07 21:45:44.588568 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5207050202@X.X.X.69) State Change CS_ROUTING -> CS_EXECUTE
2018-03-07 21:45:44.588568 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5207050202@X.X.X.69) State ROUTING going to sleep
2018-03-07 21:45:44.588568 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_EXECUTE (Cur 1 Tot 4868)
2018-03-07 21:45:44.588568 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5207050202@X.X.X.69) State EXECUTE
2018-03-07 21:45:44.588568 [DEBUG] mod_sofia.c:198 sofia/external/5207050202@X.X.X.69 SOFIA EXECUTE
2018-03-07 21:45:44.588568 [DEBUG] switch_core_state_machine.c:328 sofia/external/5207050202@X.X.X.69 Standard EXECUTE
EXECUTE sofia/external/5207050202@X.X.X.69 export(origination_callee_id_name=7401)
2018-03-07 21:45:44.588568 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[7401]
EXECUTE sofia/external/5207050202@X.X.X.69 set(RFC2822_DATE=Wed, 07 Mar 2018 21:45:44 -0700)
2018-03-07 21:45:44.588568 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [RFC2822_DATE]=[Wed, 07 Mar 2018 21:45:44 -0700]
EXECUTE sofia/external/5207050202@X.X.X.69 hash(insert/64.myvoipdomain.com-last_dial/5207050202/7401)
EXECUTE sofia/external/5207050202@X.X.X.69 set(ring_group_uuid=264e547d-425a-4655-96a4-e05fa08c85eb)
2018-03-07 21:45:44.588568 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [ring_group_uuid]=[264e547d-425a-4655-96a4-e05fa08c85eb]
EXECUTE sofia/external/5207050202@X.X.X.69 lua(app.lua ring_groups)
2018-03-07 21:45:44.588568 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x27987a0 Connected.
2018-03-07 21:45:44.588568 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('call_timeout', '300')
EXECUTE sofia/external/5207050202@X.X.X.69 ring_ready()
2018-03-07 21:45:44.588568 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/external/5207050202@X.X.X.69!
send 771 bytes to udp/[X.X.X.69]:5080 at 21:45:44.605071:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKp1Qv85aX6m6KD
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 INVITE
Contact: <sip:5203810101@X.X.X.67:5080;transport=udp>
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
X-FS-Display-Name: 5203810101
X-FS-Display-Number: sip:5203810101@X.X.X.67
X-FS-Support: update_display,send_info
P-Asserted-Identity: "5203810101" <sip:5203810101@X.X.X.67>
------------------------------------------------------------------------
2018-03-07 21:45:44.588568 [DEBUG] sofia.c:7084 Channel sofia/external/5207050202@X.X.X.69 entering state [early][180]
2018-03-07 21:45:44.588568 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/external/5207050202@X.X.X.69!
2018-03-07 21:45:44.608410 [NOTICE] switch_cpp.cpp:1365 [ring groups][call forward all] user_exists id 101 64.myvoipdomain.com
2018-03-07 21:45:44.608410 [NOTICE] switch_cpp.cpp:1365 [ring groups][call forward all] user_exists id 102 64.myvoipdomain.com
2018-03-07 21:45:44.648380 [NOTICE] switch_cpp.cpp:1365 [ring groups][call forward all] user_exists id 101 64.myvoipdomain.com
2018-03-07 21:45:44.648380 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000,4000,440,480);loops=-1')
2018-03-07 21:45:44.648380 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000,4000,440,480);loops=-1')
EXECUTE sofia/external/5207050202@X.X.X.69 set(uuids=ba71fe4e-afad-49f2-a805-a849fc6a9719)
2018-03-07 21:45:44.648380 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [uuids]=[ba71fe4e-afad-49f2-a805-a849fc6a9719]
EXECUTE sofia/external/5207050202@X.X.X.69 export(sip_h_Alert-Info=)
2018-03-07 21:45:44.648380 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5207050202@X.X.X.69 set(group_confirm_key=exec)
2018-03-07 21:45:44.648380 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [group_confirm_key]=[exec]
EXECUTE sofia/external/5207050202@X.X.X.69 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-03-07 21:45:44.648380 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-03-07 21:45:44.668413 [NOTICE] switch_cpp.cpp:1365 [ring groups][call forward all] user_exists id 102 64.myvoipdomain.com
2018-03-07 21:45:44.668413 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000,4000,440,480);loops=-1')
2018-03-07 21:45:44.668413 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000,4000,440,480);loops=-1')
EXECUTE sofia/external/5207050202@X.X.X.69 set(uuids=ba71fe4e-afad-49f2-a805-a849fc6a9719,f3116f7a-8408-4dea-b924-6d298d21112c)
2018-03-07 21:45:44.668413 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [uuids]=[ba71fe4e-afad-49f2-a805-a849fc6a9719,f3116f7a-8408-4dea-b924-6d298d21112c]
EXECUTE sofia/external/5207050202@X.X.X.69 export(sip_h_Alert-Info=)
2018-03-07 21:45:44.668413 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5207050202@X.X.X.69 set(group_confirm_key=exec)
2018-03-07 21:45:44.668413 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [group_confirm_key]=[exec]
EXECUTE sofia/external/5207050202@X.X.X.69 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-03-07 21:45:44.668413 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
EXECUTE sofia/external/5207050202@X.X.X.69 set(hangup_after_bridge=true)
2018-03-07 21:45:44.688412 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [hangup_after_bridge]=[true]
EXECUTE sofia/external/5207050202@X.X.X.69 set(continue_on_fail=true)
2018-03-07 21:45:44.688412 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [continue_on_fail]=[true]
EXECUTE sofia/external/5207050202@X.X.X.69 bind_digit_action(local,*1,exec:execute_extension,dx XML 64.myvoipdomain.com,peer)
2018-03-07 21:45:44.688412 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7f0598551d30 data: 0x27c5018
EXECUTE sofia/external/5207050202@X.X.X.69 bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/64.myvoipdomain.com/archive/2018/Mar/07/e79c8124-9fc7-4144-8459-1f547f7930ed.wav,peer)
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f0598551d30 data: 0x27c51f8
EXECUTE sofia/external/5207050202@X.X.X.69 bind_digit_action(local,*3,exec:execute_extension,cf XML 64.myvoipdomain.com,peer)
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7f0598551d30 data: 0x27c5390
EXECUTE sofia/external/5207050202@X.X.X.69 bind_digit_action(local,*4,exec:execute_extension,att_xfer XML 64.myvoipdomain.com,peer)
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7f0598551d30 data: 0x27c54e0
EXECUTE sofia/external/5207050202@X.X.X.69 digit_action_set_realm(local)
EXECUTE sofia/external/5207050202@X.X.X.69 set(call_timeout=30)
2018-03-07 21:45:44.688412 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [call_timeout]=[30]
EXECUTE sofia/external/5207050202@X.X.X.69 bridge([confirm=false,sip_invite_domain=64.myvoipdomain.com,call_direction=inbound,dialed_extension=101,extension_uuid=2d044a82-b9b7-4027-990d-562c2cd6af72,domain_name=64.myvoipdomain.com,domain_uuid=52958648-0cdf-46da-8700-adf7814389c3]user/101@64.myvoipdomain.com)
2018-03-07 21:45:44.688412 [DEBUG] switch_channel.c:1250 sofia/external/5207050202@X.X.X.69 EXPORTING[export_vars] [origination_callee_id_name]=[7401] to event
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2018-03-07 21:45:44.688412 [DEBUG] switch_channel.c:1250 sofia/external/5207050202@X.X.X.69 EXPORTING[export_vars] [origination_callee_id_name]=[7401] to event
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-03-07 21:45:44.688412 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/101@67.X.X.237:5060 [7881910b-3961-4e9a-8152-8aa959401e8d]
2018-03-07 21:45:44.688412 [DEBUG] mod_sofia.c:4819 (sofia/internal/101@67.X.X.237:5060) State Change CS_NEW -> CS_INIT
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_INIT (Cur 2 Tot 4869)
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@67.X.X.237:5060) State INIT
2018-03-07 21:45:44.688412 [DEBUG] mod_sofia.c:90 sofia/internal/101@67.X.X.237:5060 SOFIA INIT
2018-03-07 21:45:44.688412 [DEBUG] sofia_glue.c:1295 sofia/internal/101@67.X.X.237:5060 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1520457884 1520457885 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 26460 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@67.X.X.237:5060 Standard INIT
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@67.X.X.237:5060) State Change CS_INIT -> CS_ROUTING
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@67.X.X.237:5060) State INIT going to sleep
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_ROUTING (Cur 2 Tot 4869)
send 1148 bytes to udp/[67.X.X.237]:5060 at 21:45:44.706379:
------------------------------------------------------------------------
INVITE sip:101@67.X.X.237:5060 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK4FmpZgeycD49r
Max-Forwards: 68
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
To: <sip:101@67.X.X.237:5060>
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 INVITE
Contact: <sip:mod_sofia@X.X.X.67:5060>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 242
X-FS-Support: update_display,send_info
P-Asserted-Identity: "5207050202" <sip:5207050202@64.myvoipdomain.com>
v=0
o=FreeSWITCH 1520457884 1520457885 IN IP4 X.X.X.67
s=FreeSWITCH
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@67.X.X.237:5060) State ROUTING
2018-03-07 21:45:44.688412 [DEBUG] mod_sofia.c:143 sofia/internal/101@67.X.X.237:5060 SOFIA ROUTING
2018-03-07 21:45:44.688412 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/101@67.X.X.237:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@67.X.X.237:5060) State ROUTING going to sleep
c=IN IP4 X.X.X.67
t=0 0
m=audio 26460 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 4869)
2018-03-07 21:45:44.688412 [DEBUG] sofia.c:7084 Channel sofia/internal/101@67.X.X.237:5060 entering state [calling][0]
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@67.X.X.237:5060) State CONSUME_MEDIA
2018-03-07 21:45:44.688412 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@67.X.X.237:5060) State CONSUME_MEDIA going to sleep
recv 365 bytes from udp/[67.X.X.237]:5060 at 21:45:44.777358:
------------------------------------------------------------------------
SIP/2.0 100 Trying
To: <sip:101@67.X.X.237:5060>
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 INVITE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK4FmpZgeycD49r;rport=5060
Server: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
recv 515 bytes from udp/[67.X.X.237]:5060 at 21:45:44.877504:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
To: <sip:101@67.X.X.237:5060>;tag=1ead7478bd7ab35i0
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 INVITE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK4FmpZgeycD49r;rport=5060
Contact: "101" <sip:101@67.X.X.237:5060>
Server: Cisco/SPA122-1.2.1(004)
Remote-Party-ID: "101" <sip:101@64.myvoipdomain.com>;screen=yes;party=called
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:45:44.868381 [INFO] sofia.c:1279 sofia/internal/101@67.X.X.237:5060 Update Callee ID to "101" <101>
2018-03-07 21:45:44.868381 [DEBUG] sofia.c:7084 Channel sofia/internal/101@67.X.X.237:5060 entering state [proceeding][180]
2018-03-07 21:45:44.868381 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/101@67.X.X.237:5060!
2018-03-07 21:45:44.868381 [DEBUG] switch_channel.c:3346 (sofia/internal/101@67.X.X.237:5060) Callstate Change DOWN -> RINGING
2018-03-07 21:45:44.868381 [INFO] switch_ivr_originate.c:1215 Sending early media
2018-03-07 21:45:44.868381 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/5207050202@X.X.X.69] X.X.X.67 port 30332 -> X.X.X.69 port 23212 codec: 0 ms: 20
2018-03-07 21:45:44.868381 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-03-07 21:45:44.888381 [DEBUG] switch_core_media.c:7098 Activating RTCP PORT 11051
2018-03-07 21:45:44.888381 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 11051
2018-03-07 21:45:44.888381 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to X.X.X.69:11051 2
2018-03-07 21:45:44.888381 [DEBUG] switch_core_media.c:7179 sofia/external/5207050202@X.X.X.69 Set 2833 dtmf send payload to 101
2018-03-07 21:45:44.888381 [DEBUG] switch_core_media.c:7186 sofia/external/5207050202@X.X.X.69 Set 2833 dtmf receive payload to 101
2018-03-07 21:45:44.888381 [DEBUG] switch_core_media.c:7209 sofia/external/5207050202@X.X.X.69 Set rtp dtmf delay to 40
2018-03-07 21:45:44.888381 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1520454012 1520454013 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 30332 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=rtcp:30333 IN IP4 X.X.X.67
2018-03-07 21:45:44.888381 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/external/5207050202@X.X.X.69!
2018-03-07 21:45:44.888381 [DEBUG] switch_channel.c:3474 (sofia/external/5207050202@X.X.X.69) Callstate Change RINGING -> EARLY
2018-03-07 21:45:44.888381 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2018-03-07 21:45:44.888381 [DEBUG] switch_core_codec.c:223 sofia/external/5207050202@X.X.X.69 Push codec L16:100
2018-03-07 21:45:44.888381 [DEBUG] switch_ivr_originate.c:1305 Play Ringback File [tone_stream://%(2000,4000,440,480);loops=-1]
send 1069 bytes to udp/[X.X.X.69]:5080 at 21:45:44.890164:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKp1Qv85aX6m6KD
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 INVITE
Contact: <sip:5203810101@X.X.X.67:5080;transport=udp>
User-Agent: FreeSWITCH
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: 251
X-FS-Display-Name: 5203810101
X-FS-Display-Number: sip:5203810101@X.X.X.67
X-FS-Support: update_display,send_info
P-Asserted-Identity: "5203810101" <sip:5203810101@X.X.X.67>
v=0
o=FreeSWITCH 1520454012 1520454013 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 30332 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=rtcp:30333 IN IP4 X.X.X.67
------------------------------------------------------------------------
2018-03-07 21:45:44.908399 [DEBUG] sofia.c:7084 Channel sofia/external/5207050202@X.X.X.69 entering state [early][183]
2018-03-07 21:45:45.008389 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: audio ssrc[715411117] base_seq[40425]
2018-03-07 21:45:45.008389 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
------------------------------------------------------------------------
recv 459 bytes from udp/[67.X.X.237]:5060 at 21:45:48.172461:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-d68a3d7;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 8 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 656 bytes to udp/[67.X.X.237]:5060 at 21:45:48.172786:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-d68a3d7;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=5N4jUy6ZNU1NB
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 8 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 458 bytes from udp/[67.X.X.237]:5061 at 21:45:48.380279:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-fc19c94b;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 8 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 655 bytes to udp/[67.X.X.237]:5061 at 21:45:48.380514:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-fc19c94b;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=6yXBXSQ3j4Q8p
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 8 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 460 bytes from udp/[67.X.X.237]:5060 at 21:46:03.232130:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-6bd3c834;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 9 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 657 bytes to udp/[67.X.X.237]:5060 at 21:46:03.232602:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-6bd3c834;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=Bcv750BN4g75g
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 9 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 458 bytes from udp/[67.X.X.237]:5061 at 21:46:03.457212:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-af5f2e73;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 9 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 655 bytes to udp/[67.X.X.237]:5061 at 21:46:03.457677:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-af5f2e73;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=cNN07Uvr1SXrc
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 9 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
send 543 bytes to udp/[X.X.X.69]:5080 at 21:46:05.527515:
------------------------------------------------------------------------
OPTIONS sip:sbc.myvoipdomain.com:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.67:5080;rport;branch=z9hG4bK2S6jry855HFeg
Max-Forwards: 70
From: <sip:sbc.myvoipdomain.com:5080>;tag=5rNjSp13Krryr
To: <sip:sbc.myvoipdomain.com:5080>
Call-ID: 73cf9fbd-9d2e-1236-bd8b-626338373834
CSeq: 119380028 OPTIONS
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[X.X.X.69]:5080 at 21:46:05.528089:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.67:5080;rport=5080;branch=z9hG4bK2S6jry855HFeg
From: <sip:sbc.myvoipdomain.com:5080>;tag=5rNjSp13Krryr
To: <sip:sbc.myvoipdomain.com:5080>;tag=X7F9jcNBFS4Bj
Call-ID: 73cf9fbd-9d2e-1236-bd8b-626338373834
CSeq: 119380028 OPTIONS
Contact: <sip:X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:14.008388 [DEBUG] switch_core_codec.c:248 sofia/external/5207050202@X.X.X.69 Restore previous codec PCMU:0.
2018-03-07 21:46:14.008388 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/internal/101@67.X.X.237:5060 [CS_CONSUME_MEDIA] [NO_ANSWER]
2018-03-07 21:46:14.008388 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_HANGUP (Cur 2 Tot 4869)
2018-03-07 21:46:14.008388 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/101@67.X.X.237:5060) Callstate Change RINGING -> HANGUP
2018-03-07 21:46:14.008388 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@67.X.X.237:5060) State HANGUP
2018-03-07 21:46:14.008388 [DEBUG] mod_sofia.c:438 Channel sofia/internal/101@67.X.X.237:5060 hanging up, cause: NO_ANSWER
2018-03-07 21:46:14.008388 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
2018-03-07 21:46:14.008388 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 19 [NO_ANSWER]
2018-03-07 21:46:14.028385 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NO_ANSWER
2018-03-07 21:46:14.028385 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/101@67.X.X.237:5060
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:60 sofia/internal/101@67.X.X.237:5060 Standard HANGUP, cause: NO_ANSWER
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@67.X.X.237:5060) State HANGUP going to sleep
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/101@67.X.X.237:5060) State Change CS_HANGUP -> CS_REPORTING
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_REPORTING (Cur 2 Tot 4869)
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@67.X.X.237:5060) State REPORTING
send 370 bytes to udp/[67.X.X.237]:5060 at 21:46:14.029157:
------------------------------------------------------------------------
CANCEL sip:101@67.X.X.237:5060 SIP/2.0
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:174 sofia/internal/101@67.X.X.237:5060 Standard REPORTING, cause: NO_ANSWER
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK4FmpZgeycD49r
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@67.X.X.237:5060) State REPORTING going to sleep
Max-Forwards: 68
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
To: <sip:101@67.X.X.237:5060>
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 CANCEL
Reason: Q.850;cause=19;text="NO_ANSWER"
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/101@67.X.X.237:5060) State Change CS_REPORTING -> CS_DESTROY
2018-03-07 21:46:14.028385 [DEBUG] switch_core_session.c:1665 Session 4869 (sofia/internal/101@67.X.X.237:5060) Locked, Waiting on external entities
2018-03-07 21:46:14.028385 [NOTICE] switch_core_session.c:1683 Session 4869 (sofia/internal/101@67.X.X.237:5060) Ended
2018-03-07 21:46:14.028385 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/101@67.X.X.237:5060 [CS_DESTROY]
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_DESTROY (Cur 1 Tot 4869)
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@67.X.X.237:5060) State DESTROY
2018-03-07 21:46:14.028385 [DEBUG] mod_sofia.c:343 sofia/internal/101@67.X.X.237:5060 SOFIA DESTROY
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:181 sofia/internal/101@67.X.X.237:5060 Standard DESTROY
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@67.X.X.237:5060) State DESTROY going to sleep
EXECUTE sofia/external/5207050202@X.X.X.69 set(call_timeout=30)
2018-03-07 21:46:14.028385 [DEBUG] mod_dptools.c:1548 SET sofia/external/5207050202@X.X.X.69 [call_timeout]=[30]
2018-03-07 21:46:14.028385 [NOTICE] switch_cpp.cpp:1365 [ring group] app_data: {ignore_early_media=true}[sip_invite_domain=64.myvoipdomain.com,call_direction=inbound,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=101,extension_uuid=2d044a82-b9b7-4027-990d-562c2cd6af72]user/101@64.myvoipdomain.com|[sip_invite_domain=64.myvoipdomain.com,call_direction=inbound,confirm=false,leg_timeout=30,leg_delay_start=5,dialed_extension=102,extension_uuid=9f9c3c10-c7cc-4a45-b5ea-1810f685418d]user/102@64.myvoipdomain.com
EXECUTE sofia/external/5207050202@X.X.X.69 bridge({ignore_early_media=true}[sip_invite_domain=64.myvoipdomain.com,call_direction=inbound,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=101,extension_uuid=2d044a82-b9b7-4027-990d-562c2cd6af72]user/101@64.myvoipdomain.com|[sip_invite_domain=64.myvoipdomain.com,call_direction=inbound,confirm=false,leg_timeout=30,leg_delay_start=5,dialed_extension=102,extension_uuid=9f9c3c10-c7cc-4a45-b5ea-1810f685418d]user/102@64.myvoipdomain.com)
2018-03-07 21:46:14.028385 [DEBUG] switch_channel.c:1250 sofia/external/5207050202@X.X.X.69 EXPORTING[export_vars] [origination_callee_id_name]=[7401] to event
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2018-03-07 21:46:14.028385 [DEBUG] switch_channel.c:1250 sofia/external/5207050202@X.X.X.69 EXPORTING[export_vars] [origination_callee_id_name]=[7401] to event
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-03-07 21:46:14.028385 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/101@67.X.X.237:5060 [8489494b-7f2f-4ed6-b573-972aa267836c]
2018-03-07 21:46:14.028385 [DEBUG] mod_sofia.c:4819 (sofia/internal/101@67.X.X.237:5060) State Change CS_NEW -> CS_INIT
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:2963 sofia/internal/101@67.X.X.237:5060 Setting leg timeout to 30
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:2963 sofia/internal/101@67.X.X.237:5060 Setting leg timeout to 30
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_INIT (Cur 2 Tot 4870)
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@67.X.X.237:5060) State INIT
2018-03-07 21:46:14.028385 [DEBUG] mod_sofia.c:90 sofia/internal/101@67.X.X.237:5060 SOFIA INIT
2018-03-07 21:46:14.028385 [DEBUG] sofia_glue.c:1295 sofia/internal/101@67.X.X.237:5060 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1520457894 1520457895 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 26480 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@67.X.X.237:5060 Standard INIT
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@67.X.X.237:5060) State Change CS_INIT -> CS_ROUTING
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@67.X.X.237:5060) State INIT going to sleep
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_ROUTING (Cur 2 Tot 4870)
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@67.X.X.237:5060) State ROUTING
send 1148 bytes to udp/[67.X.X.237]:5060 at 21:46:14.043810:
------------------------------------------------------------------------
INVITE sip:101@67.X.X.237:5060 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK5rDF1BZ19Ntvm
2018-03-07 21:46:14.028385 [DEBUG] mod_sofia.c:143 sofia/internal/101@67.X.X.237:5060 SOFIA ROUTING
Max-Forwards: 68
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
To: <sip:101@67.X.X.237:5060>
2018-03-07 21:46:14.028385 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/101@67.X.X.237:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906123 INVITE
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@67.X.X.237:5060) State ROUTING going to sleep
Contact: <sip:mod_sofia@X.X.X.67:5060>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Privacy: none
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 242
X-FS-Support: update_display,send_info
P-Asserted-Identity: "5207050202" <sip:5207050202@64.myvoipdomain.com>
v=0
o=FreeSWITCH 1520457894 1520457895 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 26480 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 4870)
2018-03-07 21:46:14.028385 [DEBUG] sofia.c:7084 Channel sofia/internal/101@67.X.X.237:5060 entering state [calling][0]
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@67.X.X.237:5060) State CONSUME_MEDIA
2018-03-07 21:46:14.028385 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@67.X.X.237:5060) State CONSUME_MEDIA going to sleep
recv 399 bytes from udp/[67.X.X.237]:5060 at 21:46:14.074853:
------------------------------------------------------------------------
SIP/2.0 487 Request Terminated
To: <sip:101@67.X.X.237:5060>;tag=1ead7478bd7ab35i0
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 INVITE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK4FmpZgeycD49r;rport=5060
Server: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 345 bytes to udp/[67.X.X.237]:5060 at 21:46:14.075029:
------------------------------------------------------------------------
ACK sip:101@67.X.X.237:5060 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK4FmpZgeycD49r
Max-Forwards: 68
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
To: <sip:101@67.X.X.237:5060>;tag=1ead7478bd7ab35i0
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 ACK
Content-Length: 0
------------------------------------------------------------------------
recv 383 bytes from udp/[67.X.X.237]:5060 at 21:46:14.082335:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:101@67.X.X.237:5060>;tag=1ead7478bd7ab35i0
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=33H1Q84rU9mgm
Call-ID: 67668f65-9d2e-1236-bd8b-626338373834
CSeq: 119906108 CANCEL
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK4FmpZgeycD49r;rport=5060
Server: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
recv 365 bytes from udp/[67.X.X.237]:5060 at 21:46:14.162682:
------------------------------------------------------------------------
SIP/2.0 100 Trying
To: <sip:101@67.X.X.237:5060>
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906123 INVITE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK5rDF1BZ19Ntvm;rport=5060
Server: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
recv 461 bytes from udp/[67.X.X.237]:5060 at 21:46:18.282453:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-36a2e23d;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 10 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 658 bytes to udp/[67.X.X.237]:5060 at 21:46:18.282770:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-36a2e23d;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=jBDNjy1DgF38H
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 10 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 459 bytes from udp/[67.X.X.237]:5061 at 21:46:18.545246:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-595339e4;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 10 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 656 bytes to udp/[67.X.X.237]:5061 at 21:46:18.545601:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-595339e4;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=Km6DmSjHDrSUD
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 10 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
send 543 bytes to udp/[X.X.X.69]:5080 at 21:46:30.553937:
------------------------------------------------------------------------
OPTIONS sip:sbc.myvoipdomain.com:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.67:5080;rport;branch=z9hG4bK32ZBtSS92t50B
Max-Forwards: 70
From: <sip:sbc.myvoipdomain.com:5080>;tag=61eBUHj7g1eHm
To: <sip:sbc.myvoipdomain.com:5080>
Call-ID: 82ba5b1d-9d2e-1236-bd8b-626338373834
CSeq: 119380029 OPTIONS
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[X.X.X.69]:5080 at 21:46:30.554579:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.67:5080;rport=5080;branch=z9hG4bK32ZBtSS92t50B
From: <sip:sbc.myvoipdomain.com:5080>;tag=61eBUHj7g1eHm
To: <sip:sbc.myvoipdomain.com:5080>;tag=ZS2tp2pj9aHHS
Call-ID: 82ba5b1d-9d2e-1236-bd8b-626338373834
CSeq: 119380029 OPTIONS
Contact: <sip:X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 461 bytes from udp/[67.X.X.237]:5060 at 21:46:33.384962:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-6fe333c7;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 11 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 658 bytes to udp/[67.X.X.237]:5060 at 21:46:33.385235:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-6fe333c7;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=r149v062y48rQ
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 11 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 459 bytes from udp/[67.X.X.237]:5061 at 21:46:33.642109:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-b6a70bc8;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 11 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 656 bytes to udp/[67.X.X.237]:5061 at 21:46:33.642477:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-b6a70bc8;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=Say2yUQ6UDZBK
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 11 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 879 bytes from udp/[67.X.X.237]:5060 at 21:46:42.187510:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:101@67.X.X.237:5060>;tag=8f156975d6339a5bi0
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906123 INVITE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK5rDF1BZ19Ntvm;rport=5060
Contact: "101" <sip:101@67.X.X.237:5060>
Server: Cisco/SPA122-1.2.1(004)
Remote-Party-ID: "101" <sip:101@64.myvoipdomain.com>;screen=yes;party=called
Allow-Events: talk, hold, conference
Content-Length: 251
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp
v=0
o=- 19149 19149 IN IP4 67.X.X.237
s=-
c=IN IP4 67.X.X.237
t=0 0
m=audio 16460 RTP/AVP 0 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
2018-03-07 21:46:42.188380 [INFO] sofia.c:1279 sofia/internal/101@67.X.X.237:5060 Update Callee ID to "101" <101>
2018-03-07 21:46:42.188380 [DEBUG] sofia.c:7084 Channel sofia/internal/101@67.X.X.237:5060 entering state [completing][200]
2018-03-07 21:46:42.188380 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 19149 19149 IN IP4 67.X.X.237
s=-
c=IN IP4 67.X.X.237
t=0 0
m=audio 16460 RTP/AVP 0 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
send 389 bytes to udp/[67.X.X.237]:5060 at 21:46:42.189703:
------------------------------------------------------------------------
ACK sip:101@67.X.X.237:5060 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK616726F56ygFg
Max-Forwards: 70
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
To: <sip:101@67.X.X.237:5060>;tag=8f156975d6339a5bi0
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906123 ACK
Contact: <sip:mod_sofia@X.X.X.67:5060>
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:42.188380 [DEBUG] sofia.c:7084 Channel sofia/internal/101@67.X.X.237:5060 entering state [ready][200]
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [NSE:100:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/101@67.X.X.237:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-03-07 21:46:42.188380 [DEBUG] switch_core_codec.c:111 sofia/internal/101@67.X.X.237:5060 Original read codec set to PCMU:0
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:4767 sofia/internal/101@67.X.X.237:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/101@67.X.X.237:5060] X.X.X.67 port 26480 -> 67.X.X.237 port 16460 codec: 0 ms: 20
2018-03-07 21:46:42.188380 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:7179 sofia/internal/101@67.X.X.237:5060 Set 2833 dtmf send payload to 101
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:7186 sofia/internal/101@67.X.X.237:5060 Set 2833 dtmf receive payload to 101
2018-03-07 21:46:42.188380 [DEBUG] switch_core_media.c:7209 sofia/internal/101@67.X.X.237:5060 Set rtp dtmf delay to 40
2018-03-07 21:46:42.188380 [NOTICE] sofia.c:8218 Channel [sofia/internal/101@67.X.X.237:5060] has been answered
2018-03-07 21:46:42.188380 [DEBUG] switch_channel.c:3773 (sofia/internal/101@67.X.X.237:5060) Callstate Change DOWN -> ACTIVE
EXECUTE sofia/internal/101@67.X.X.237:5060 lua(/usr/share/freeswitch/scripts/confirm.lua)
2018-03-07 21:46:42.208386 [DEBUG] switch_cpp.cpp:1112 sofia/internal/101@67.X.X.237:5060 destroy/unlink session from object
2018-03-07 21:46:42.208386 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/external/5207050202@X.X.X.69.
2018-03-07 21:46:42.208386 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/5207050202@X.X.X.69:
v=0
o=FreeSWITCH 1520454012 1520454014 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 30332 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=rtcp:30333 IN IP4 X.X.X.67
send 1027 bytes to udp/[X.X.X.69]:5080 at 21:46:42.227592:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKp1Qv85aX6m6KD
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 INVITE
Contact: <sip:5203810101@X.X.X.67:5080;transport=udp>
User-Agent: FreeSWITCH
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: 251
X-FS-Display-Name: 101
X-FS-Display-Number: sip:101@X.X.X.67
X-FS-Support: update_display,send_info
P-Asserted-Identity: "101" <sip:101@X.X.X.67>
2018-03-07 21:46:42.208386 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/external/5207050202@X.X.X.69] has been answered
v=0
o=FreeSWITCH 1520454012 1520454013 IN IP4 X.X.X.67
s=FreeSWITCH
c=IN IP4 X.X.X.67
t=0 0
m=audio 30332 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=rtcp:30333 IN IP4 X.X.X.67
------------------------------------------------------------------------
2018-03-07 21:46:42.208386 [DEBUG] switch_channel.c:3773 (sofia/external/5207050202@X.X.X.69) Callstate Change EARLY -> ACTIVE
2018-03-07 21:46:42.228709 [DEBUG] sofia.c:7084 Channel sofia/external/5207050202@X.X.X.69 entering state [completed][200]
2018-03-07 21:46:42.228709 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/101@67.X.X.237:5060]
2018-03-07 21:46:42.228709 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/101@67.X.X.237:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-03-07 21:46:42.228709 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 4870)
2018-03-07 21:46:42.228709 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/101@67.X.X.237:5060) State EXCHANGE_MEDIA
2018-03-07 21:46:42.228709 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
recv 402 bytes from udp/[X.X.X.69]:5080 at 21:46:42.231121:
------------------------------------------------------------------------
ACK sip:5203810101@X.X.X.67:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.69:5080;rport;branch=z9hG4bKQaHNa1U03Xv6r
Max-Forwards: 70
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935938 ACK
Contact: <sip:mod_sofia@X.X.X.69:5080>
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:42.228709 [DEBUG] sofia.c:7084 Channel sofia/external/5207050202@X.X.X.69 entering state [ready][200]
send 640 bytes to udp/[X.X.X.69]:5080 at 21:46:42.267257:
------------------------------------------------------------------------
INFO sip:mod_sofia@X.X.X.69:5080 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67:5080;rport;branch=z9hG4bK4BS4UmaD03UKQ
Max-Forwards: 70
From: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
To: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119906137 INFO
Contact: <sip:5203810101@X.X.X.67:5080;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Type: message/update_display
Content-Length: 0
X-FS-Display-Name: 101
X-FS-Display-Number: 101
------------------------------------------------------------------------
recv 527 bytes from udp/[X.X.X.69]:5080 at 21:46:42.269495:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.67:5080;rport=5080;branch=z9hG4bK4BS4UmaD03UKQ
From: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
To: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119906137 INFO
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
recv 729 bytes from udp/[X.X.X.69]:5080 at 21:46:42.278288:
------------------------------------------------------------------------
INFO sip:5203810101@X.X.X.67:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.69:5080;rport;branch=z9hG4bKrKaecvc406jSm
Max-Forwards: 70
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935939 INFO
Contact: <sip:mod_sofia@X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Type: message/update_display
Content-Length: 0
X-FS-Display-Name: 5207050202
X-FS-Display-Number: 5207050202
------------------------------------------------------------------------
2018-03-07 21:46:42.268832 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
send 452 bytes to udp/[X.X.X.69]:5080 at 21:46:42.288901:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKrKaecvc406jSm
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935939 INFO
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:42.328402 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
------------------------------------------------------------------------
recv 461 bytes from udp/[67.X.X.237]:5060 at 21:46:48.442608:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-32a0b183;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 12 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 658 bytes to udp/[67.X.X.237]:5060 at 21:46:48.442907:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-32a0b183;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=yQvy72BrDte9c
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 12 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 459 bytes from udp/[67.X.X.237]:5061 at 21:46:48.727452:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-86434f22;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 12 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 656 bytes to udp/[67.X.X.237]:5061 at 21:46:48.727807:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-86434f22;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=Z0NQ9XvUa34Ur
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 12 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 649 bytes from udp/[X.X.X.69]:5080 at 21:46:50.886134:
------------------------------------------------------------------------
BYE sip:5203810101@X.X.X.67:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.69:5080;rport;branch=z9hG4bKSv36DQX7XF9Bg
Max-Forwards: 70
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935940 BYE
Contact: <sip:mod_sofia@X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Reason: Q.850;cause=16
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:50.868389 [NOTICE] sofia.c:1012 Hangup sofia/external/5207050202@X.X.X.69 [CS_EXECUTE] [NORMAL_CLEARING]
send 451 bytes to udp/[X.X.X.69]:5080 at 21:46:50.888559:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.69:5080;rport=5080;branch=z9hG4bKSv36DQX7XF9Bg
From: "5207050202" <sip:5207050202@X.X.X.69>;tag=UNXQFpK4m7Q6a
To: <sip:5203810101@X.X.X.67:5080>;tag=4FvSQUg0pF2BD
Call-ID: 4ffaf53c-9db9-1236-91a0-623962333032
CSeq: 119935940 BYE
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:50.888379 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/5207050202@X.X.X.69]
2018-03-07 21:46:50.888379 [DEBUG] switch_ivr_bridge.c:706 sofia/external/5207050202@X.X.X.69 ending bridge by request from write function
2018-03-07 21:46:50.888379 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/101@67.X.X.237:5060]
2018-03-07 21:46:50.888379 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/internal/101@67.X.X.237:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2018-03-07 21:46:50.888379 [DEBUG] switch_ivr_bridge.c:1712 sofia/internal/101@67.X.X.237:5060 skip receive message [UNBRIDGE] (channel is hungup already)
2018-03-07 21:46:50.888379 [DEBUG] switch_ivr_bridge.c:1715 sofia/external/5207050202@X.X.X.69 skip receive message [UNBRIDGE] (channel is hungup already)
2018-03-07 21:46:50.888379 [DEBUG] switch_core_session.c:2815 sofia/external/5207050202@X.X.X.69 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-03-07 21:46:50.888379 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x27987a0 released.
2018-03-07 21:46:50.888379 [DEBUG] switch_cpp.cpp:1112 sofia/external/5207050202@X.X.X.69 destroy/unlink session from object
2018-03-07 21:46:50.888379 [DEBUG] switch_core_session.c:2815 sofia/external/5207050202@X.X.X.69 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5207050202@X.X.X.69) State EXECUTE going to sleep
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_HANGUP (Cur 2 Tot 4870)
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5207050202@X.X.X.69) Callstate Change ACTIVE -> HANGUP
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:852 (sofia/external/5207050202@X.X.X.69) State HANGUP
2018-03-07 21:46:50.888379 [DEBUG] mod_sofia.c:438 Channel sofia/external/5207050202@X.X.X.69 hanging up, cause: NORMAL_CLEARING
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:60 sofia/external/5207050202@X.X.X.69 Standard HANGUP, cause: NORMAL_CLEARING
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:852 (sofia/external/5207050202@X.X.X.69) State HANGUP going to sleep
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:619 (sofia/external/5207050202@X.X.X.69) State Change CS_HANGUP -> CS_REPORTING
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5207050202@X.X.X.69) Running State Change CS_REPORTING (Cur 2 Tot 4870)
2018-03-07 21:46:50.888379 [DEBUG] switch_core_state_machine.c:938 (sofia/external/5207050202@X.X.X.69) State REPORTING
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/101@67.X.X.237:5060) State EXCHANGE_MEDIA going to sleep
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_HANGUP (Cur 2 Tot 4870)
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/101@67.X.X.237:5060) Callstate Change ACTIVE -> HANGUP
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@67.X.X.237:5060) State HANGUP
2018-03-07 21:46:50.909008 [DEBUG] mod_sofia.c:432 sofia/internal/101@67.X.X.237:5060 Overriding SIP cause 480 with 200 from the other leg
2018-03-07 21:46:50.909008 [DEBUG] mod_sofia.c:438 Channel sofia/internal/101@67.X.X.237:5060 hanging up, cause: NORMAL_CLEARING
2018-03-07 21:46:50.909008 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/101@67.X.X.237:5060
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:60 sofia/internal/101@67.X.X.237:5060 Standard HANGUP, cause: NORMAL_CLEARING
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@67.X.X.237:5060) State HANGUP going to sleep
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/101@67.X.X.237:5060) State Change CS_HANGUP -> CS_REPORTING
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_REPORTING (Cur 2 Tot 4870)
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@67.X.X.237:5060) State REPORTING
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:174 sofia/internal/101@67.X.X.237:5060 Standard REPORTING, cause: NORMAL_CLEARING
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@67.X.X.237:5060) State REPORTING going to sleep
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/101@67.X.X.237:5060) State Change CS_REPORTING -> CS_DESTROY
2018-03-07 21:46:50.909008 [DEBUG] switch_core_session.c:1665 Session 4870 (sofia/internal/101@67.X.X.237:5060) Locked, Waiting on external entities
2018-03-07 21:46:50.909008 [NOTICE] switch_core_session.c:1683 Session 4870 (sofia/internal/101@67.X.X.237:5060) Ended
2018-03-07 21:46:50.909008 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/101@67.X.X.237:5060 [CS_DESTROY]
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/101@67.X.X.237:5060) Running State Change CS_DESTROY (Cur 1 Tot 4870)
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@67.X.X.237:5060) State DESTROY
2018-03-07 21:46:50.909008 [DEBUG] mod_sofia.c:343 sofia/internal/101@67.X.X.237:5060 SOFIA DESTROY
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:181 sofia/internal/101@67.X.X.237:5060 Standard DESTROY
2018-03-07 21:46:50.909008 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@67.X.X.237:5060) State DESTROY going to sleep
send 538 bytes to udp/[67.X.X.237]:5060 at 21:46:50.919483:
------------------------------------------------------------------------
BYE sip:101@67.X.X.237:5060 SIP/2.0
Via: SIP/2.0/UDP X.X.X.67;rport;branch=z9hG4bK7a0041083761B
Max-Forwards: 70
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
To: <sip:101@67.X.X.237:5060>;tag=8f156975d6339a5bi0
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906124 BYE
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Reason: Q.850;cause=16
Content-Length: 0
------------------------------------------------------------------------
recv 464 bytes from udp/[67.X.X.237]:5060 at 21:46:51.002664:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:101@67.X.X.237:5060>;tag=8f156975d6339a5bi0
From: "5207050202" <sip:5207050202@64.myvoipdomain.com>;tag=gSt3e8Z6NXp3a
Call-ID: 78e31ab7-9d2e-1236-bd8b-626338373834
CSeq: 119906124 BYE
Via: SIP/2.0/UDP X.X.X.67;branch=z9hG4bK7a0041083761B;rport=5060
Server: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
P-RTP-Stat: PS=434,OS=69440,PR=428,OR=68480,PL=3,JI=0,LA=0,DU=8,EN=G711u,DE=G711u
Content-Length: 0
------------------------------------------------------------------------
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:174 sofia/external/5207050202@X.X.X.69 Standard REPORTING, cause: NORMAL_CLEARING
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:938 (sofia/external/5207050202@X.X.X.69) State REPORTING going to sleep
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:610 (sofia/external/5207050202@X.X.X.69) State Change CS_REPORTING -> CS_DESTROY
2018-03-07 21:46:51.008396 [DEBUG] switch_core_session.c:1665 Session 4868 (sofia/external/5207050202@X.X.X.69) Locked, Waiting on external entities
2018-03-07 21:46:51.008396 [NOTICE] switch_core_session.c:1683 Session 4868 (sofia/external/5207050202@X.X.X.69) Ended
2018-03-07 21:46:51.008396 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/5207050202@X.X.X.69 [CS_DESTROY]
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:741 (sofia/external/5207050202@X.X.X.69) Running State Change CS_DESTROY (Cur 0 Tot 4870)
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:751 (sofia/external/5207050202@X.X.X.69) State DESTROY
2018-03-07 21:46:51.008396 [DEBUG] mod_sofia.c:343 sofia/external/5207050202@X.X.X.69 SOFIA DESTROY
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:181 sofia/external/5207050202@X.X.X.69 Standard DESTROY
2018-03-07 21:46:51.008396 [DEBUG] switch_core_state_machine.c:751 (sofia/external/5207050202@X.X.X.69) State DESTROY going to sleep
send 543 bytes to udp/[X.X.X.69]:5080 at 21:46:55.581628:
------------------------------------------------------------------------
OPTIONS sip:sbc.myvoipdomain.com:5080;transport=udp SIP/2.0
Via: SIP/2.0/UDP X.X.X.67:5080;rport;branch=z9hG4bK5mjXXFUgXcj6j
Max-Forwards: 70
From: <sip:sbc.myvoipdomain.com:5080>;tag=7a83vc3aea53F
To: <sip:sbc.myvoipdomain.com:5080>
Call-ID: 91a546df-9d2e-1236-bd8b-626338373834
CSeq: 119380030 OPTIONS
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[X.X.X.69]:5080 at 21:46:55.582374:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP X.X.X.67:5080;rport=5080;branch=z9hG4bK5mjXXFUgXcj6j
From: <sip:sbc.myvoipdomain.com:5080>;tag=7a83vc3aea53F
To: <sip:sbc.myvoipdomain.com:5080>;tag=1BNctrrS3vXpg
Call-ID: 91a546df-9d2e-1236-bd8b-626338373834
CSeq: 119380030 OPTIONS
Contact: <sip:X.X.X.69:5080>
User-Agent: FreeSWITCH-mod_sofia/1.2.24+git~20150504T151740Z~da04da87df~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 461 bytes from udp/[67.X.X.237]:5060 at 21:47:03.482640:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-7accbbd3;rport
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 13 NOTIFY
Max-Forwards: 70
Contact: "101" <sip:101@67.X.X.237:5060;ref=101>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 658 bytes to udp/[67.X.X.237]:5060 at 21:47:03.483014:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5060;branch=z9hG4bK-7accbbd3;rport=5060
From: "101" <sip:101@64.myvoipdomain.com>;tag=13f6156b3c36b54bo0
To: <sip:64.myvoipdomain.com>;tag=4DmKj5gDvFmSj
Call-ID: 4a378aeb-5527bdcb@67.X.X.237
CSeq: 13 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------
recv 459 bytes from udp/[67.X.X.237]:5061 at 21:47:03.780177:
------------------------------------------------------------------------
NOTIFY sip:64.myvoipdomain.com SIP/2.0
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-d5964ef4;rport
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 13 NOTIFY
Max-Forwards: 70
Contact: "102" <sip:102@67.X.X.237:5061;ref=102>
Event: keep-alive
User-Agent: Cisco/SPA122-1.2.1(004)
Allow-Events: talk, hold, conference
Content-Length: 0
------------------------------------------------------------------------
send 656 bytes to udp/[67.X.X.237]:5061 at 21:47:03.780557:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 67.X.X.237:5061;branch=z9hG4bK-d5964ef4;rport=5061
From: "102" <sip:102@64.myvoipdomain.com>;tag=7c76146b421ec24bo1
To: <sip:64.myvoipdomain.com>;tag=5pDcm01gSrace
Call-ID: ca286b-d1b9be4b@67.X.X.237
CSeq: 13 NOTIFY
Contact: <sip:X.X.X.67>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
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
Content-Length: 0
------------------------------------------------------------------------