Call drops Every 30Sec
- Thread starter adi
- Start date
- Status
You have a NAT issue, what version of Freeswitch are you running? Also, post the WHOLE call from the INVITE not just the 200OK.
My switch version is 1.8.7. hope this log helps, Giving each phone a public will solve the issue??
send 325 bytes to udp/[196.53.96.54]:5062 at 08:52:40.892384:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
User-Agent: FreeSWITCH
Content-Length: 0
------------------------------------------------------------------------
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->user_exists] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1003@xyz.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(user_exists=false)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [user_exists]=[false]
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->caller-details] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_destination=100998866)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_destination]=[100998866]
Dialplan: sofia/internal/1003@xyz.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_id_name=1003)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_id_name]=[1003]
Dialplan: sofia/internal/1003@xyz.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->variables] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/1003@xyz.com Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/1003@xyz.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->call-direction] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/1003@xyz.com ANTI-Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(call_direction=local)
2019-09-05 08:52:40.470910 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->is_loopback] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->user_record] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->redial] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [redial] destination_number(100998866) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1003@xyz.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->speed_dial] continue=false
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [speed_dial] destination_number(100998866) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->default_caller_id] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(emergency_caller_id_name=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [emergency_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/1003@xyz.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(emergency_caller_id_number=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [emergency_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(+14357522266) =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] continue=false
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] destination_number(100998866) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/1003@xyz.com Action export(call_direction=outbound)
Dialplan: sofia/internal/1003@xyz.com Action unset(call_timeout)
Dialplan: sofia/internal/1003@xyz.com Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1003@xyz.com Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/1003@xyz.com Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/1003@xyz.com Action set(inherit_codec=true)
Dialplan: sofia/internal/1003@xyz.com Action set(ignore_display_updates=true)
Dialplan: sofia/internal/1003@xyz.com Action set(callee_id_number=00998866)
Dialplan: sofia/internal/1003@xyz.com Action set(continue_on_fail=true)
Dialplan: sofia/internal/1003@xyz.com Action sleep(${sleep})
Dialplan: sofia/internal/1003@xyz.com Action bridge(sofia/gateway/14e08762-f4bc-4fe6-b002-cb910b47beb1/+100998866)
Dialplan: sofia/internal/1003@xyz.com Action bridge(sofia/gateway/231a9902-231c-47af-a857-8b440b51403a/+100998866)
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1003@xyz.com) State Change CS_ROUTING -> CS_EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@xyz.com) State ROUTING going to sleep
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@xyz.com) Running State Change CS_EXECUTE (Cur 1 Tot 957)
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@xyz.com) State EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] mod_sofia.c:209 sofia/internal/1003@xyz.com SOFIA EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1003@xyz.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_id_number=1003)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_id_number]=[1003]
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(origination_callee_id_name=100998866)
2019-09-05 08:52:40.470910 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [origination_callee_id_name]=[100998866]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(RFC2822_DATE=Thu, 05 Sep 2019 08:52:40 -0600)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [RFC2822_DATE]=[Thu, 05 Sep 2019 08:52:40 -0600]
EXECUTE [depth=0] sofia/internal/1003@xyz.com hash(insert/xyz.com-last_dial/1003/100998866)
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(sip_h_X-accountcode=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [sip_h_X-accountcode]=[UNDEF]
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(call_direction=outbound)
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/internal/1003@xyz.com unset(call_timeout)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1760 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(hangup_after_bridge=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(effective_caller_id_name=)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [effective_caller_id_name]=[UNDEF]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(effective_caller_id_number=+14357522266)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [effective_caller_id_number]=[+14357522266]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(inherit_codec=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(ignore_display_updates=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(callee_id_number=00998866)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [callee_id_number]=[00998866]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(continue_on_fail=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com sleep(0)
EXECUTE [depth=0] sofia/internal/1003@xyz.com bridge(sofia/gateway/14e08762-f4bc-4fe6-b002-cb910b47beb1/+100998866)
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [domain_name]=[xyz.com] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [origination_callee_id_name]=[100998866] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_ivr_originate.c:2209 Parsing global variables
2019-09-05 08:52:40.490900 [NOTICE] switch_channel.c:1114 New Channel sofia/external/+100998866 [37925532-32eb-4320-bb4a-13cee745db00]
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:5031 (sofia/external/+100998866) State Change CS_NEW -> CS_INIT
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_INIT (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+100998866) State INIT
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:93 sofia/external/+100998866 SOFIA INIT
2019-09-05 08:52:40.490900 [DEBUG] sofia_glue.c:1315 sofia/external/+100998866 sending invite version: 1.8.7 -8-6047ebddfc 64bit
Local SDP:
v=0
o=FreeSWITCH 1567676940 1567676941 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 18220 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:40 sofia/external/+100998866 Standard INIT
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+100998866) State Change CS_INIT -> CS_ROUTING
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+100998866) State INIT going to sleep
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_ROUTING (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+100998866) State ROUTING
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:154 sofia/external/+100998866 SOFIA ROUTING
2019-09-05 08:52:40.490900 [DEBUG] switch_ivr_originate.c:67 (sofia/external/+100998866) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+100998866) State ROUTING going to sleep
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [calling][0]
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:662 (sofia/external/+100998866) State CONSUME_MEDIA
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:662 (sofia/external/+100998866) State CONSUME_MEDIA going to sleep
send 1213 bytes to udp/[54.244.51.2]:5060 at 08:52:41.108872:
------------------------------------------------------------------------
INVITE sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com SIP/2.0
Via: SIP/2.0/UDP 196.53.97.23:5080;rport;branch=z9hG4bKjBB77NBa7j07K
Max-Forwards: 69
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 INVITE
Contact: <sip:gw+14e08762-f4bc-4fe6-b002-cb910b47beb1@196.53.97.23:5080;transport=udp;gw=14e08762-f4bc-4fe6-b002-cb910b47beb1>
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: 268
X-FS-Support: update_display,send_info
Remote-Party-ID: "1003" <sip:+14357522266@fusionpbx-wi-fiber.pstn.us2.twilio.com>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1567676940 1567676941 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 18220 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
recv 388 bytes from udp/[54.244.51.2]:5060 at 08:52:41.139864:
------------------------------------------------------------------------
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 INVITE
Server: Twilio Gateway
Content-Length: 0
------------------------------------------------------------------------
recv 861 bytes from udp/[54.244.51.2]:5060 at 08:52:42.809964:
------------------------------------------------------------------------
SIP/2.0 183 Session progress
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
Content-Type: application/sdp
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 236
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 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
------------------------------------------------------------------------
2019-09-05 08:52:42.370956 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [proceeding][183]
2019-09-05 08:52:42.370956 [DEBUG] sofia.c:7333 Remote SDP:
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2019-09-05 08:52:42.370956 [NOTICE] sofia.c:7336 Pre-Answer sofia/external/+100998866!
2019-09-05 08:52:42.370956 [DEBUG] switch_channel.c:3526 (sofia/external/+100998866) Callstate Change DOWN -> EARLY
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5566 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5427 Set telephone-event payload to 101@8000
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:3781 Set Codec sofia/external/+100998866 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-09-05 08:52:42.370956 [DEBUG] switch_core_codec.c:111 sofia/external/+100998866 Original read codec set to PCMU:0
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5770 Set telephone-event payload to 101@8000
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5828 sofia/external/+100998866 Set 2833 dtmf send payload to 101 recv payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8568 AUDIO RTP [sofia/external/+100998866] 196.53.97.23 port 18220 -> 54.244.51.51 port 12502 codec: 0 ms: 20
2019-09-05 08:52:42.370956 [DEBUG] switch_rtp.c:4349 Starting timer [soft] 160 bytes per 20ms
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8875 sofia/external/+100998866 Set 2833 dtmf send payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8882 sofia/external/+100998866 Set 2833 dtmf receive payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8905 sofia/external/+100998866 Set rtp dtmf delay to 40
2019-09-05 08:52:42.370956 [DEBUG] switch_ivr_originate.c:436 Setting codec string on sofia/internal/1003@xyz.com to PCMU@8000h@20i
2019-09-05 08:52:42.370956 [INFO] switch_ivr_originate.c:3752 Sending early media
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8568 AUDIO RTP [sofia/internal/1003@xyz.com] 196.53.97.23 port 25546 -> 196.53.96.54 port 5024 codec: 0 ms: 20
2019-09-05 08:52:42.370956 [DEBUG] switch_rtp.c:4349 Starting timer [soft] 160 bytes per 20ms
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8875 sofia/internal/1003@xyz.com Set 2833 dtmf send payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8882 sofia/internal/1003@xyz.com Set 2833 dtmf receive payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8905 sofia/internal/1003@xyz.com Set rtp dtmf delay to 40
2019-09-05 08:52:42.390919 [DEBUG] mod_sofia.c:2515 Ring SDP:
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 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
2019-09-05 08:52:42.390919 [NOTICE] mod_sofia.c:2518 Pre-Answer sofia/internal/1003@xyz.com!
2019-09-05 08:52:42.390919 [DEBUG] switch_channel.c:3526 (sofia/internal/1003@xyz.com) Callstate Change RINGING -> EARLY
2019-09-05 08:52:42.390919 [DEBUG] switch_ivr_originate.c:3803 Originate Resulted in Success: [sofia/external/+100998866]
send 1179 bytes to udp/[196.53.96.54]:5062 at 08:52:42.831740:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
Contact: <sip:100998866@196.53.97.23:5060;transport=udp>
User-Agent: FreeSWITCH
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, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 220
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
P-Asserted-Identity: "100998866" <sip:00998866@xyz.com>
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2019-09-05 08:52:42.390919 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [early][183]
2019-09-05 08:52:42.390919 [DEBUG] switch_ivr_bridge.c:1795 (sofia/external/+100998866) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2019-09-05 08:52:42.390919 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 958)
2019-09-05 08:52:42.390919 [DEBUG] switch_core_state_machine.c:653 (sofia/external/+100998866) State EXCHANGE_MEDIA
2019-09-05 08:52:42.390919 [DEBUG] mod_sofia.c:657 SOFIA EXCHANGE_MEDIA
2019-09-05 08:52:42.430902 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
2019-09-05 08:52:42.710907 [INFO] switch_rtp.c:7564 Auto Changing audio port from 196.53.96.54:5024 to 196.53.96.54:65416
recv 583 bytes from udp/[54.244.51.2]:5060 at 08:52:44.520412:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:44.090971 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [proceeding][180]
2019-09-05 08:52:44.090971 [NOTICE] sofia.c:7433 Ring-Ready sofia/external/+100998866!
2019-09-05 08:52:44.090971 [DEBUG] switch_channel.c:3398 (sofia/external/+100998866) Callstate Change EARLY -> RINGING
recv 875 bytes from tcp/[208.83.225.238]:33146 at 08:52:49.362652:
------------------------------------------------------------------------
REGISTER sip:bundy.fusionpbx.wi-fiber.io SIP/2.0
From: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=1655106821
To: <sip:202@bundy.fusionpbx.wi-fiber.io>
Call-ID: 847894956-5060-1@BA.B.EA.BBB
CSeq: 2625 REGISTER
Authorization: Digest username="202", realm="bundy.fusionpbx.wi-fiber.io", nonce="e3981ccf-e0fa-4c91-9887-c73ff405f382", uri="sip:bundy.fusionpbx.wi-fiber.io", response="efcfcc6e1d9d4e33341464711c6125e4", algorithm=MD5, cnonce="01235034", qop=auth, nc=0000020a
Max-Forwards: 70
User-Agent: Grandstream GXP1405 1.0.5.23
Supported: path
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
Via: SIP/2.0/TCP 208.83.225.238:33146;rport;branch=z9hG4bK474083359
Contact: <sip:202@208.83.225.238:33146;transport=tcp>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-1000-8000-000B8249449F>"
Expires: 180
------------------------------------------------------------------------
send 565 bytes to tcp/[208.83.225.238]:33146 at 08:52:49.374180:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 208.83.225.238:33146;rport=33146;branch=z9hG4bK474083359
From: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=1655106821
To: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=356FBDQ83r1Nr
Call-ID: 847894956-5060-1@BA.B.EA.BBB
CSeq: 2625 REGISTER
Contact: <sip:202@208.83.225.238:33146;transport=tcp>;expires=180
Date: Thu, 05 Sep 2019 14:52:48 GMT
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
recv 898 bytes from udp/[54.244.51.2]:5060 at 08:52:51.982013:
------------------------------------------------------------------------
SIP/2.0 200 OK
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY
Content-Type: application/sdp
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 236
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 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
------------------------------------------------------------------------
2019-09-05 08:52:51.550918 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [completing][200]
2019-09-05 08:52:51.550918 [DEBUG] sofia.c:7330 Duplicate SDP
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
send 602 bytes to udp/[54.244.51.2]:5060 at 08:52:51.996204:
------------------------------------------------------------------------
ACK sip:172.18.67.116:5060 SIP/2.0
Via: SIP/2.0/UDP 196.53.97.23:5080;rport;branch=z9hG4bKKm4Z9gvD4UptF
Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Max-Forwards: 70
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 ACK
Contact: <sip:gw+14e08762-f4bc-4fe6-b002-cb910b47beb1@196.53.97.23:5080;transport=udp;gw=14e08762-f4bc-4fe6-b002-cb910b47beb1>
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:51.570994 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [ready][200]
2019-09-05 08:52:51.570994 [NOTICE] sofia.c:8402 Channel [sofia/external/+100998866] has been answered
2019-09-05 08:52:51.570994 [DEBUG] switch_channel.c:3825 (sofia/external/+100998866) Callstate Change RINGING -> ACTIVE
2019-09-05 08:52:51.570994 [DEBUG] switch_core_media.c:8551 Audio params are unchanged for sofia/internal/1003@xyz.com.
2019-09-05 08:52:51.590906 [DEBUG] mod_sofia.c:893 Local SDP sofia/internal/1003@xyz.com:
v=0
o=FreeSWITCH 1567669616 1567669618 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 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
send 1140 bytes to udp/[196.53.96.54]:5062 at 08:52:52.030332:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
Contact: <sip:100998866@196.53.97.23:5060;transport=udp>
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-Type: application/sdp
Content-Disposition: session
Content-Length: 220
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
P-Asserted-Identity: "100998866" <sip:00998866@xyz.com>
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2019-09-05 08:52:51.590906 [NOTICE] switch_ivr_bridge.c:736 Channel [sofia/internal/1003@xyz.com] has been answered
2019-09-05 08:52:51.590906 [DEBUG] switch_channel.c:3825 (sofia/internal/1003@xyz.com) Callstate Change EARLY -> ACTIVE
2019-09-05 08:52:51.590906 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [completed][200]
recv 873 bytes from udp/[196.53.96.54]:5062 at 08:52:52.068278:
------------------------------------------------------------------------
ACK sip:100998866@196.53.97.23:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK960129694;rport
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 ACK
Contact: <sip:1003@196.53.96.54:5062>
Proxy-Authorization: Digest username="1003", realm="xyz.com", nonce="8e1e47da-c7c5-4666-b5da-9ecab6296d2b", uri="sip:100998866@xyz.com", response="71f694dbc233f023fd80390a5f262d66", algorithm=MD5, cnonce="01661652", qop=auth, nc=00000001
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1630 1.0.4.128
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:51.610928 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
2019-09-05 08:52:51.610928 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [ready][200]
2019-09-05 08:52:51.630906 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
recv 875 bytes from tcp/[208.83.225.238]:55503 at 08:53:18.801646:
------------------------------------------------------------------------
REGISTER sip:bundy.fusionpbx.wi-fiber.io SIP/2.0
From: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=1499420971
To: <sip:201@bundy.fusionpbx.wi-fiber.io>
Call-ID: 589497314-5060-1@BA.B.EA.BBC
CSeq: 2626 REGISTER
Authorization: Digest username="201", realm="bundy.fusionpbx.wi-fiber.io", nonce="a6805cd1-f7a9-45b4-966a-033374e52f86", uri="sip:bundy.fusionpbx.wi-fiber.io", response="1630f7bca98471bf12e4c270193e3037", algorithm=MD5, cnonce="09608762", qop=auth, nc=00000239
Max-Forwards: 70
User-Agent: Grandstream GXP1405 1.0.5.58
Supported: path
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
Via: SIP/2.0/TCP 208.83.225.238:55503;rport;branch=z9hG4bK161857848
Contact: <sip:201@208.83.225.238:55503;transport=tcp>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-1000-8000-000B8241258A>"
Expires: 180
------------------------------------------------------------------------
send 565 bytes to tcp/[208.83.225.238]:55503 at 08:53:18.814853:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 208.83.225.238:55503;rport=55503;branch=z9hG4bK161857848
From: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=1499420971
To: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=4e08c87B11Q8K
Call-ID: 589497314-5060-1@BA.B.EA.BBC
CSeq: 2626 REGISTER
Contact: <sip:201@208.83.225.238:55503;transport=tcp>;expires=180
Date: Thu, 05 Sep 2019 14:53:18 GMT
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
freeswitch@FusionPBX/
Unknown command []
recv 577 bytes from udp/[196.53.96.54]:5062 at 08:53:37.566186:
------------------------------------------------------------------------
BYE sip:100998866@196.53.97.23:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1219444681;rport
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 122 BYE
Contact: <sip:1003@196.53.96.54:5062>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1630 1.0.4.128
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:53:37.130911 [NOTICE] sofia.c:1079 Hangup sofia/internal/1003@xyz.com [CS_EXECUTE] [NORMAL_CLEARING]
send 480 bytes to udp/[196.53.96.54]:5062 at 08:53:37.571038:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1219444681;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 122 BYE
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1003@xyz.com]
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1003@xyz.com ending bridge by request from write function
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/external/+100998866]
2019-09-05 08:53:37.130911 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/external/+100998866 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:653 (sofia/external/+100998866) State EXCHANGE_MEDIA going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_HANGUP (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:847 (sofia/external/+100998866) Callstate Change ACTIVE -> HANGUP
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:1894 sofia/external/+100998866 skip receive message [UNBRIDGE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:1897 sofia/internal/1003@xyz.com skip receive message [UNBRIDGE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+100998866) State HANGUP
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:454 sofia/external/+100998866 Overriding SIP cause 480 with 200 from the other leg
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:460 Channel sofia/external/+100998866 hanging up, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:513 Sending BYE to sofia/external/+100998866
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:60 sofia/external/+100998866 Standard HANGUP, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+100998866) State HANGUP going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+100998866) State Change CS_HANGUP -> CS_REPORTING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_REPORTING (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_session.c:2905 sofia/internal/1003@xyz.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+100998866) State REPORTING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@xyz.com) State EXECUTE going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@xyz.com) Running State Change CS_HANGUP (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:174 sofia/external/+100998866 Standard REPORTING, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+100998866) State REPORTING going to sleep
send 325 bytes to udp/[196.53.96.54]:5062 at 08:52:40.892384:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
User-Agent: FreeSWITCH
Content-Length: 0
------------------------------------------------------------------------
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->user_exists] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1003@xyz.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(user_exists=false)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [user_exists]=[false]
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->caller-details] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_destination=100998866)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_destination]=[100998866]
Dialplan: sofia/internal/1003@xyz.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_id_name=1003)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_id_name]=[1003]
Dialplan: sofia/internal/1003@xyz.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->variables] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/1003@xyz.com Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/1003@xyz.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->call-direction] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/1003@xyz.com ANTI-Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(call_direction=local)
2019-09-05 08:52:40.470910 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->is_loopback] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->user_record] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_exists}() =~ /^true$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->redial] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [redial] destination_number(100998866) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1003@xyz.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->speed_dial] continue=false
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [speed_dial] destination_number(100998866) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->default_caller_id] continue=true
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(emergency_caller_id_name=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [emergency_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/1003@xyz.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(emergency_caller_id_number=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [emergency_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/1003@xyz.com Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(+14357522266) =~ /^$/ break=never
Dialplan: sofia/internal/1003@xyz.com parsing [xyz.com->fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] continue=false
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1003@xyz.com Regex (PASS) [fusionpbx-wi-fiber.pstn.us2.twilio.com.1d10] destination_number(100998866) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1003@xyz.com Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/1003@xyz.com Action export(call_direction=outbound)
Dialplan: sofia/internal/1003@xyz.com Action unset(call_timeout)
Dialplan: sofia/internal/1003@xyz.com Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1003@xyz.com Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/1003@xyz.com Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/1003@xyz.com Action set(inherit_codec=true)
Dialplan: sofia/internal/1003@xyz.com Action set(ignore_display_updates=true)
Dialplan: sofia/internal/1003@xyz.com Action set(callee_id_number=00998866)
Dialplan: sofia/internal/1003@xyz.com Action set(continue_on_fail=true)
Dialplan: sofia/internal/1003@xyz.com Action sleep(${sleep})
Dialplan: sofia/internal/1003@xyz.com Action bridge(sofia/gateway/14e08762-f4bc-4fe6-b002-cb910b47beb1/+100998866)
Dialplan: sofia/internal/1003@xyz.com Action bridge(sofia/gateway/231a9902-231c-47af-a857-8b440b51403a/+100998866)
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1003@xyz.com) State Change CS_ROUTING -> CS_EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@xyz.com) State ROUTING going to sleep
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@xyz.com) Running State Change CS_EXECUTE (Cur 1 Tot 957)
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@xyz.com) State EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] mod_sofia.c:209 sofia/internal/1003@xyz.com SOFIA EXECUTE
2019-09-05 08:52:40.470910 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1003@xyz.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(caller_id_number=1003)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [caller_id_number]=[1003]
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(origination_callee_id_name=100998866)
2019-09-05 08:52:40.470910 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [origination_callee_id_name]=[100998866]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(RFC2822_DATE=Thu, 05 Sep 2019 08:52:40 -0600)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [RFC2822_DATE]=[Thu, 05 Sep 2019 08:52:40 -0600]
EXECUTE [depth=0] sofia/internal/1003@xyz.com hash(insert/xyz.com-last_dial/1003/100998866)
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(sip_h_X-accountcode=)
2019-09-05 08:52:40.470910 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [sip_h_X-accountcode]=[UNDEF]
EXECUTE [depth=0] sofia/internal/1003@xyz.com export(call_direction=outbound)
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1306 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/internal/1003@xyz.com unset(call_timeout)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1760 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(hangup_after_bridge=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(effective_caller_id_name=)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [effective_caller_id_name]=[UNDEF]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(effective_caller_id_number=+14357522266)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [effective_caller_id_number]=[+14357522266]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(inherit_codec=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(ignore_display_updates=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(callee_id_number=00998866)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [callee_id_number]=[00998866]
EXECUTE [depth=0] sofia/internal/1003@xyz.com set(continue_on_fail=true)
2019-09-05 08:52:40.490900 [DEBUG] mod_dptools.c:1615 SET sofia/internal/1003@xyz.com [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/internal/1003@xyz.com sleep(0)
EXECUTE [depth=0] sofia/internal/1003@xyz.com bridge(sofia/gateway/14e08762-f4bc-4fe6-b002-cb910b47beb1/+100998866)
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [domain_name]=[xyz.com] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [origination_callee_id_name]=[100998866] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_channel.c:1260 sofia/internal/1003@xyz.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2019-09-05 08:52:40.490900 [DEBUG] switch_ivr_originate.c:2209 Parsing global variables
2019-09-05 08:52:40.490900 [NOTICE] switch_channel.c:1114 New Channel sofia/external/+100998866 [37925532-32eb-4320-bb4a-13cee745db00]
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:5031 (sofia/external/+100998866) State Change CS_NEW -> CS_INIT
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_INIT (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+100998866) State INIT
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:93 sofia/external/+100998866 SOFIA INIT
2019-09-05 08:52:40.490900 [DEBUG] sofia_glue.c:1315 sofia/external/+100998866 sending invite version: 1.8.7 -8-6047ebddfc 64bit
Local SDP:
v=0
o=FreeSWITCH 1567676940 1567676941 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 18220 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:40 sofia/external/+100998866 Standard INIT
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+100998866) State Change CS_INIT -> CS_ROUTING
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+100998866) State INIT going to sleep
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_ROUTING (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+100998866) State ROUTING
2019-09-05 08:52:40.490900 [DEBUG] mod_sofia.c:154 sofia/external/+100998866 SOFIA ROUTING
2019-09-05 08:52:40.490900 [DEBUG] switch_ivr_originate.c:67 (sofia/external/+100998866) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+100998866) State ROUTING going to sleep
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 958)
2019-09-05 08:52:40.490900 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [calling][0]
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:662 (sofia/external/+100998866) State CONSUME_MEDIA
2019-09-05 08:52:40.490900 [DEBUG] switch_core_state_machine.c:662 (sofia/external/+100998866) State CONSUME_MEDIA going to sleep
send 1213 bytes to udp/[54.244.51.2]:5060 at 08:52:41.108872:
------------------------------------------------------------------------
INVITE sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com SIP/2.0
Via: SIP/2.0/UDP 196.53.97.23:5080;rport;branch=z9hG4bKjBB77NBa7j07K
Max-Forwards: 69
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 INVITE
Contact: <sip:gw+14e08762-f4bc-4fe6-b002-cb910b47beb1@196.53.97.23:5080;transport=udp;gw=14e08762-f4bc-4fe6-b002-cb910b47beb1>
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: 268
X-FS-Support: update_display,send_info
Remote-Party-ID: "1003" <sip:+14357522266@fusionpbx-wi-fiber.pstn.us2.twilio.com>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1567676940 1567676941 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 18220 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
recv 388 bytes from udp/[54.244.51.2]:5060 at 08:52:41.139864:
------------------------------------------------------------------------
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 INVITE
Server: Twilio Gateway
Content-Length: 0
------------------------------------------------------------------------
recv 861 bytes from udp/[54.244.51.2]:5060 at 08:52:42.809964:
------------------------------------------------------------------------
SIP/2.0 183 Session progress
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
Content-Type: application/sdp
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 236
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 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
------------------------------------------------------------------------
2019-09-05 08:52:42.370956 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [proceeding][183]
2019-09-05 08:52:42.370956 [DEBUG] sofia.c:7333 Remote SDP:
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2019-09-05 08:52:42.370956 [NOTICE] sofia.c:7336 Pre-Answer sofia/external/+100998866!
2019-09-05 08:52:42.370956 [DEBUG] switch_channel.c:3526 (sofia/external/+100998866) Callstate Change DOWN -> EARLY
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5566 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5427 Set telephone-event payload to 101@8000
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:3781 Set Codec sofia/external/+100998866 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-09-05 08:52:42.370956 [DEBUG] switch_core_codec.c:111 sofia/external/+100998866 Original read codec set to PCMU:0
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5770 Set telephone-event payload to 101@8000
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:5828 sofia/external/+100998866 Set 2833 dtmf send payload to 101 recv payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8568 AUDIO RTP [sofia/external/+100998866] 196.53.97.23 port 18220 -> 54.244.51.51 port 12502 codec: 0 ms: 20
2019-09-05 08:52:42.370956 [DEBUG] switch_rtp.c:4349 Starting timer [soft] 160 bytes per 20ms
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8875 sofia/external/+100998866 Set 2833 dtmf send payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8882 sofia/external/+100998866 Set 2833 dtmf receive payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8905 sofia/external/+100998866 Set rtp dtmf delay to 40
2019-09-05 08:52:42.370956 [DEBUG] switch_ivr_originate.c:436 Setting codec string on sofia/internal/1003@xyz.com to PCMU@8000h@20i
2019-09-05 08:52:42.370956 [INFO] switch_ivr_originate.c:3752 Sending early media
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8568 AUDIO RTP [sofia/internal/1003@xyz.com] 196.53.97.23 port 25546 -> 196.53.96.54 port 5024 codec: 0 ms: 20
2019-09-05 08:52:42.370956 [DEBUG] switch_rtp.c:4349 Starting timer [soft] 160 bytes per 20ms
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8875 sofia/internal/1003@xyz.com Set 2833 dtmf send payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8882 sofia/internal/1003@xyz.com Set 2833 dtmf receive payload to 101
2019-09-05 08:52:42.370956 [DEBUG] switch_core_media.c:8905 sofia/internal/1003@xyz.com Set rtp dtmf delay to 40
2019-09-05 08:52:42.390919 [DEBUG] mod_sofia.c:2515 Ring SDP:
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 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
2019-09-05 08:52:42.390919 [NOTICE] mod_sofia.c:2518 Pre-Answer sofia/internal/1003@xyz.com!
2019-09-05 08:52:42.390919 [DEBUG] switch_channel.c:3526 (sofia/internal/1003@xyz.com) Callstate Change RINGING -> EARLY
2019-09-05 08:52:42.390919 [DEBUG] switch_ivr_originate.c:3803 Originate Resulted in Success: [sofia/external/+100998866]
send 1179 bytes to udp/[196.53.96.54]:5062 at 08:52:42.831740:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
Contact: <sip:100998866@196.53.97.23:5060;transport=udp>
User-Agent: FreeSWITCH
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, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 220
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
P-Asserted-Identity: "100998866" <sip:00998866@xyz.com>
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2019-09-05 08:52:42.390919 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [early][183]
2019-09-05 08:52:42.390919 [DEBUG] switch_ivr_bridge.c:1795 (sofia/external/+100998866) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2019-09-05 08:52:42.390919 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 958)
2019-09-05 08:52:42.390919 [DEBUG] switch_core_state_machine.c:653 (sofia/external/+100998866) State EXCHANGE_MEDIA
2019-09-05 08:52:42.390919 [DEBUG] mod_sofia.c:657 SOFIA EXCHANGE_MEDIA
2019-09-05 08:52:42.430902 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
2019-09-05 08:52:42.710907 [INFO] switch_rtp.c:7564 Auto Changing audio port from 196.53.96.54:5024 to 196.53.96.54:65416
recv 583 bytes from udp/[54.244.51.2]:5060 at 08:52:44.520412:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:44.090971 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [proceeding][180]
2019-09-05 08:52:44.090971 [NOTICE] sofia.c:7433 Ring-Ready sofia/external/+100998866!
2019-09-05 08:52:44.090971 [DEBUG] switch_channel.c:3398 (sofia/external/+100998866) Callstate Change EARLY -> RINGING
recv 875 bytes from tcp/[208.83.225.238]:33146 at 08:52:49.362652:
------------------------------------------------------------------------
REGISTER sip:bundy.fusionpbx.wi-fiber.io SIP/2.0
From: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=1655106821
To: <sip:202@bundy.fusionpbx.wi-fiber.io>
Call-ID: 847894956-5060-1@BA.B.EA.BBB
CSeq: 2625 REGISTER
Authorization: Digest username="202", realm="bundy.fusionpbx.wi-fiber.io", nonce="e3981ccf-e0fa-4c91-9887-c73ff405f382", uri="sip:bundy.fusionpbx.wi-fiber.io", response="efcfcc6e1d9d4e33341464711c6125e4", algorithm=MD5, cnonce="01235034", qop=auth, nc=0000020a
Max-Forwards: 70
User-Agent: Grandstream GXP1405 1.0.5.23
Supported: path
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
Via: SIP/2.0/TCP 208.83.225.238:33146;rport;branch=z9hG4bK474083359
Contact: <sip:202@208.83.225.238:33146;transport=tcp>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-1000-8000-000B8249449F>"
Expires: 180
------------------------------------------------------------------------
send 565 bytes to tcp/[208.83.225.238]:33146 at 08:52:49.374180:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 208.83.225.238:33146;rport=33146;branch=z9hG4bK474083359
From: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=1655106821
To: <sip:202@bundy.fusionpbx.wi-fiber.io>;tag=356FBDQ83r1Nr
Call-ID: 847894956-5060-1@BA.B.EA.BBB
CSeq: 2625 REGISTER
Contact: <sip:202@208.83.225.238:33146;transport=tcp>;expires=180
Date: Thu, 05 Sep 2019 14:52:48 GMT
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
recv 898 bytes from udp/[54.244.51.2]:5060 at 08:52:51.982013:
------------------------------------------------------------------------
SIP/2.0 200 OK
CSeq: 9293788 INVITE
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Via: SIP/2.0/UDP 196.53.97.23:5080;received=196.53.97.23;rport=5080;branch=z9hG4bKjBB77NBa7j07K
Record-Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Server: Twilio
Contact: <sip:172.18.67.116:5060>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY
Content-Type: application/sdp
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
Content-Length: 236
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 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
------------------------------------------------------------------------
2019-09-05 08:52:51.550918 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [completing][200]
2019-09-05 08:52:51.550918 [DEBUG] sofia.c:7330 Duplicate SDP
v=0
o=root 1937627834 1937627834 IN IP4 54.244.51.51
s=Twilio Media Gateway
c=IN IP4 54.244.51.51
t=0 0
m=audio 12502 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
send 602 bytes to udp/[54.244.51.2]:5060 at 08:52:51.996204:
------------------------------------------------------------------------
ACK sip:172.18.67.116:5060 SIP/2.0
Via: SIP/2.0/UDP 196.53.97.23:5080;rport;branch=z9hG4bKKm4Z9gvD4UptF
Route: <sip:54.244.51.2:5060;lr;ftag=m4D1jpKa2pNcm>
Max-Forwards: 70
From: "1003" <sip:FreeSWITCH@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=m4D1jpKa2pNcm
To: <sip:+100998866@fusionpbx-wi-fiber.pstn.us2.twilio.com>;tag=68319943_6772d868_03cd5ff1-a75a-4462-b6be-bdecf5347ff2
Call-ID: a6b60846-4a8f-1238-c98e-5254009b035f
CSeq: 9293788 ACK
Contact: <sip:gw+14e08762-f4bc-4fe6-b002-cb910b47beb1@196.53.97.23:5080;transport=udp;gw=14e08762-f4bc-4fe6-b002-cb910b47beb1>
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:51.570994 [DEBUG] sofia.c:7323 Channel sofia/external/+100998866 entering state [ready][200]
2019-09-05 08:52:51.570994 [NOTICE] sofia.c:8402 Channel [sofia/external/+100998866] has been answered
2019-09-05 08:52:51.570994 [DEBUG] switch_channel.c:3825 (sofia/external/+100998866) Callstate Change RINGING -> ACTIVE
2019-09-05 08:52:51.570994 [DEBUG] switch_core_media.c:8551 Audio params are unchanged for sofia/internal/1003@xyz.com.
2019-09-05 08:52:51.590906 [DEBUG] mod_sofia.c:893 Local SDP sofia/internal/1003@xyz.com:
v=0
o=FreeSWITCH 1567669616 1567669618 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 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
send 1140 bytes to udp/[196.53.96.54]:5062 at 08:52:52.030332:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1513676999;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 INVITE
Contact: <sip:100998866@196.53.97.23:5060;transport=udp>
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-Type: application/sdp
Content-Disposition: session
Content-Length: 220
X-Twilio-CallSid: CA58d9b79f4428e200e03b5cea0cbd7097
P-Asserted-Identity: "100998866" <sip:00998866@xyz.com>
v=0
o=FreeSWITCH 1567669616 1567669617 IN IP4 196.53.97.23
s=FreeSWITCH
c=IN IP4 196.53.97.23
t=0 0
m=audio 25546 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2019-09-05 08:52:51.590906 [NOTICE] switch_ivr_bridge.c:736 Channel [sofia/internal/1003@xyz.com] has been answered
2019-09-05 08:52:51.590906 [DEBUG] switch_channel.c:3825 (sofia/internal/1003@xyz.com) Callstate Change EARLY -> ACTIVE
2019-09-05 08:52:51.590906 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [completed][200]
recv 873 bytes from udp/[196.53.96.54]:5062 at 08:52:52.068278:
------------------------------------------------------------------------
ACK sip:100998866@196.53.97.23:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK960129694;rport
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 121 ACK
Contact: <sip:1003@196.53.96.54:5062>
Proxy-Authorization: Digest username="1003", realm="xyz.com", nonce="8e1e47da-c7c5-4666-b5da-9ecab6296d2b", uri="sip:100998866@xyz.com", response="71f694dbc233f023fd80390a5f262d66", algorithm=MD5, cnonce="01661652", qop=auth, nc=00000001
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1630 1.0.4.128
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:52:51.610928 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
2019-09-05 08:52:51.610928 [DEBUG] sofia.c:7323 Channel sofia/internal/1003@xyz.com entering state [ready][200]
2019-09-05 08:52:51.630906 [DEBUG] switch_rtp.c:7604 Correct audio ip/port confirmed.
recv 875 bytes from tcp/[208.83.225.238]:55503 at 08:53:18.801646:
------------------------------------------------------------------------
REGISTER sip:bundy.fusionpbx.wi-fiber.io SIP/2.0
From: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=1499420971
To: <sip:201@bundy.fusionpbx.wi-fiber.io>
Call-ID: 589497314-5060-1@BA.B.EA.BBC
CSeq: 2626 REGISTER
Authorization: Digest username="201", realm="bundy.fusionpbx.wi-fiber.io", nonce="a6805cd1-f7a9-45b4-966a-033374e52f86", uri="sip:bundy.fusionpbx.wi-fiber.io", response="1630f7bca98471bf12e4c270193e3037", algorithm=MD5, cnonce="09608762", qop=auth, nc=00000239
Max-Forwards: 70
User-Agent: Grandstream GXP1405 1.0.5.58
Supported: path
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
Via: SIP/2.0/TCP 208.83.225.238:55503;rport;branch=z9hG4bK161857848
Contact: <sip:201@208.83.225.238:55503;transport=tcp>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-1000-8000-000B8241258A>"
Expires: 180
------------------------------------------------------------------------
send 565 bytes to tcp/[208.83.225.238]:55503 at 08:53:18.814853:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 208.83.225.238:55503;rport=55503;branch=z9hG4bK161857848
From: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=1499420971
To: <sip:201@bundy.fusionpbx.wi-fiber.io>;tag=4e08c87B11Q8K
Call-ID: 589497314-5060-1@BA.B.EA.BBC
CSeq: 2626 REGISTER
Contact: <sip:201@208.83.225.238:55503;transport=tcp>;expires=180
Date: Thu, 05 Sep 2019 14:53:18 GMT
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
freeswitch@FusionPBX/
Unknown command []
recv 577 bytes from udp/[196.53.96.54]:5062 at 08:53:37.566186:
------------------------------------------------------------------------
BYE sip:100998866@196.53.97.23:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1219444681;rport
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 122 BYE
Contact: <sip:1003@196.53.96.54:5062>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1630 1.0.4.128
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:53:37.130911 [NOTICE] sofia.c:1079 Hangup sofia/internal/1003@xyz.com [CS_EXECUTE] [NORMAL_CLEARING]
send 480 bytes to udp/[196.53.96.54]:5062 at 08:53:37.571038:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 196.53.96.54:5062;branch=z9hG4bK1219444681;rport=5062
From: <sip:1003@xyz.com>;tag=2072409930
To: <sip:100998866@xyz.com>;tag=2vDQ9H646FB3c
Call-ID: 433616897-5062-15@BJC.BGI.A.BGJ
CSeq: 122 BYE
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1003@xyz.com]
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1003@xyz.com ending bridge by request from write function
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/external/+100998866]
2019-09-05 08:53:37.130911 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/external/+100998866 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:653 (sofia/external/+100998866) State EXCHANGE_MEDIA going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_HANGUP (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:847 (sofia/external/+100998866) Callstate Change ACTIVE -> HANGUP
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:1894 sofia/external/+100998866 skip receive message [UNBRIDGE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_ivr_bridge.c:1897 sofia/internal/1003@xyz.com skip receive message [UNBRIDGE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+100998866) State HANGUP
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:454 sofia/external/+100998866 Overriding SIP cause 480 with 200 from the other leg
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:460 Channel sofia/external/+100998866 hanging up, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] mod_sofia.c:513 Sending BYE to sofia/external/+100998866
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:60 sofia/external/+100998866 Standard HANGUP, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+100998866) State HANGUP going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+100998866) State Change CS_HANGUP -> CS_REPORTING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+100998866) Running State Change CS_REPORTING (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_session.c:2905 sofia/internal/1003@xyz.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+100998866) State REPORTING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@xyz.com) State EXECUTE going to sleep
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@xyz.com) Running State Change CS_HANGUP (Cur 2 Tot 958)
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:174 sofia/external/+100998866 Standard REPORTING, cause: NORMAL_CLEARING
2019-09-05 08:53:37.130911 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+100998866) State REPORTING going to sleep
Then I would think you may have a SIP ALG enabled on your router. Have a look and disable it if it is.
I was my first thing to do. I disabled it and opened ports 5060 and 5080 from external to internal. I changed my sip profile to ext-sip-ip and ext-rto-ip to auto nat thinking it would solve my NAT issue but one of my location is having 30sec and other location is 1 min.
Last edited:
- Status