recv 1791 bytes from udp/[139.59.34.94]:5060 at 20:26:36.573215: ------------------------------------------------------------------------ INVITE sip:1001@139.59.81.245:34807;transport=udp;gw=signalwire_prod SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bK5fde.c1f2cb88d60d5b878a0fd3b9dfd4a691.0;i=804 Via: SIP/2.0/TLS 138.68.46.209:35181;received=138.68.46.209;rport=43634;branch=z9hG4bK105m2Nj6ym9yj Max-Forwards: 63 From: "CALIFORNIA " ;tag=grmN85UvDXrgH To: Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 CSeq: 14305105 INVITE Contact: User-Agent: SignalWire STACK Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Session-Expires: 600;refresher=uac Min-SE: 90 Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 497 P-SRC-IP: 147.75.65.195 X-Relay-Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 X-CID: 1646798335_57904152@23.29.23.120 X-FS-Support: update_display,send_info P-Asserted-Identity: "CALIFORNIA " v=0 o=SignalWire-STACK 1577699049 1577699050 IN IP4 138.68.46.209 s=SignalWire-STACK c=IN IP4 138.68.46.209 t=0 0 m=audio 18746 RTP/SAVP 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=crypto:1 AEAD_AES_256_GCM_8 inline:lHMErHQ2AMk0ub2CXc2CFzv0az4EKTYVRZmimQWEj8V4rRMhomIM79yguzg= a=ptime:20 m=audio 18746 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 2019-12-30 20:26:36.565496 [NOTICE] switch_channel.c:1118 New Channel sofia/external/+16503820000@sip.signalwire.com [85420fdb-4ed0-48e6-8220-999062f2f580] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_NEW (Cur 1 Tot 61) 2019-12-30 20:26:36.565496 [DEBUG] sofia.c:10243 sofia/external/+16503820000@sip.signalwire.com receiving invite from 139.59.34.94:5060 version: 20.19.6 -release-14-2b31de9 64bit 2019-12-30 20:26:36.565496 [DEBUG] sofia.c:7290 Channel sofia/external/+16503820000@sip.signalwire.com entering state [received][100] 2019-12-30 20:26:36.565496 [DEBUG] sofia.c:7300 Remote SDP: v=0 o=SignalWire-STACK 1577699049 1577699050 IN IP4 138.68.46.209 s=SignalWire-STACK c=IN IP4 138.68.46.209 t=0 0 m=audio 18746 RTP/SAVP 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=crypto:1 AEAD_AES_256_GCM_8 inline:lHMErHQ2AMk0ub2CXc2CFzv0az4EKTYVRZmimQWEj8V4rRMhomIM79yguzg= a=ptime:20 m=audio 18746 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 2019-12-30 20:26:36.565496 [DEBUG] sofia.c:7703 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_NEW -> CS_INIT 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:604 (sofia/external/+16503820000@sip.signalwire.com) State NEW 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_INIT (Cur 1 Tot 61) 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+16503820000@sip.signalwire.com) State INIT 2019-12-30 20:26:36.565496 [DEBUG] mod_sofia.c:93 sofia/external/+16503820000@sip.signalwire.com SOFIA INIT 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:40 sofia/external/+16503820000@sip.signalwire.com Standard INIT 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_INIT -> CS_ROUTING 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+16503820000@sip.signalwire.com) State INIT going to sleep 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_ROUTING (Cur 1 Tot 61) 2019-12-30 20:26:36.565496 [DEBUG] switch_channel.c:2332 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change DOWN -> RINGING 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+16503820000@sip.signalwire.com) State ROUTING send 410 bytes to udp/[139.59.34.94]:5060 at 20:26:36.575736: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bK5fde.c1f2cb88d60d5b878a0fd3b9dfd4a691.0;i=804 From: "CALIFORNIA " ;tag=grmN85UvDXrgH To: Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 CSeq: 14305105 INVITE User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit Content-Length: 0 2019-12-30 20:26:36.565496 [DEBUG] mod_sofia.c:154 sofia/external/+16503820000@sip.signalwire.com SOFIA ROUTING 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:236 sofia/external/+16503820000@sip.signalwire.com Standard ROUTING 2019-12-30 20:26:36.565496 [INFO] mod_dialplan_xml.c:637 Processing CALIFORNIA <+16503820000>->1001 in context public Dialplan: sofia/external/+16503820000@sip.signalwire.com parsing [public->lua-env-hangup-hook-test] continue=false Dialplan: sofia/external/+16503820000@sip.signalwire.com Regex (PASS) [lua-env-hangup-hook-test] destination_number(1001) =~ /^(.*)$/ break=on-false Dialplan: sofia/external/+16503820000@sip.signalwire.com Action pre_answer() Dialplan: sofia/external/+16503820000@sip.signalwire.com Action playback(/usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3) Dialplan: sofia/external/+16503820000@sip.signalwire.com Action hangup() 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:287 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_ROUTING -> CS_EXECUTE 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+16503820000@sip.signalwire.com) State ROUTING going to sleep 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_EXECUTE (Cur 1 Tot 61) 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:651 (sofia/external/+16503820000@sip.signalwire.com) State EXECUTE 2019-12-30 20:26:36.565496 [DEBUG] mod_sofia.c:209 sofia/external/+16503820000@sip.signalwire.com SOFIA EXECUTE 2019-12-30 20:26:36.565496 [DEBUG] switch_core_state_machine.c:329 sofia/external/+16503820000@sip.signalwire.com Standard EXECUTE EXECUTE [depth=0] sofia/external/+16503820000@sip.signalwire.com pre_answer() 2019-12-30 20:26:36.565496 [INFO] mod_dptools.c:1477 Sending early media 2019-12-30 20:26:36.565496 [WARNING] switch_core_media.c:5475 Received invite with SAVP but secure media is administratively disabled 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5648 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5509 Set telephone-event payload to 101@8000 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:3837 Set Codec sofia/external/+16503820000@sip.signalwire.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2019-12-30 20:26:36.565496 [DEBUG] switch_core_codec.c:111 sofia/external/+16503820000@sip.signalwire.com Original read codec set to PCMU:0 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5852 Set telephone-event payload to 101@8000 2019-12-30 20:26:36.565496 [DEBUG] switch_core_media.c:5910 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf send payload to 101 recv payload to 101 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:8109 STUN Success [139.59.81.245]:[22522] 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:8113 STUN Not Required ip and port match. [139.59.81.245]:[22522] 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:8682 AUDIO RTP [sofia/external/+16503820000@sip.signalwire.com] 139.59.81.245 port 22522 -> 138.68.46.209 port 18746 codec: 0 ms: 20 2019-12-30 20:26:36.805503 [DEBUG] switch_rtp.c:4496 Starting timer [soft] 160 bytes per 20ms 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:8996 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf send payload to 101 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:9003 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf receive payload to 101 2019-12-30 20:26:36.805503 [DEBUG] switch_core_media.c:9026 sofia/external/+16503820000@sip.signalwire.com Set rtp dtmf delay to 40 2019-12-30 20:26:36.805503 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/+16503820000@sip.signalwire.com! 2019-12-30 20:26:36.825476 [DEBUG] switch_channel.c:3565 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change RINGING -> EARLY 2019-12-30 20:26:36.825476 [DEBUG] switch_core_media.c:8664 Audio params are unchanged for sofia/external/+16503820000@sip.signalwire.com. 2019-12-30 20:26:36.825476 [DEBUG] mod_sofia.c:2600 Ring SDP: v=0 o=FreeSWITCH 1577695274 1577695275 IN IP4 139.59.81.245 s=FreeSWITCH c=IN IP4 139.59.81.245 t=0 0 m=audio 22522 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 1436 bytes to udp/[139.59.34.94]:5060 at 20:26:36.826645: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bK5fde.c1f2cb88d60d5b878a0fd3b9dfd4a691.0;i=804 Via: SIP/2.0/TLS 138.68.46.209:35181;received=138.68.46.209;rport=43634;branch=z9hG4bK105m2Nj6ym9yj Record-Route: Record-Route: From: "CALIFORNIA " ;tag=grmN85UvDXrgH To: ;tag=c03a1gS30FmcH Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 CSeq: 14305105 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit 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-Type: application/sdp Content-Disposition: session Content-Length: 245 X-FS-Display-Name: 1001 X-FS-Display-Number: sip:1001@shashi-fs-12345.sip.signalwire.com X-FS-Support: update_display,send_info P-Asserted-Identity: "1001" v=0 o=FreeSWITCH 1577695274 1577695275 IN IP4 139.59.81.245 s=FreeSWITCH c=IN IP4 139.59.81.245 t=0 0 m=audio 0 RTP/SAVP 19 m=audio 22522 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2019-12-30 20:26:36.825476 [DEBUG] sofia.c:7290 Channel sofia/external/+16503820000@sip.signalwire.com entering state [early][183] EXECUTE [depth=0] sofia/external/+16503820000@sip.signalwire.com playback(/usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3) 2019-12-30 20:26:36.825476 [DEBUG] switch_ivr_play_say.c:1492 Codec Activated L16@8000hz 1 channels 20ms send 868 bytes to udp/[190.102.98.218]:5060 at 20:26:49.789521: ------------------------------------------------------------------------ REGISTER sip:dev-phones.sip.swire.io;transport=udp SIP/2.0 Via: SIP/2.0/UDP 139.59.81.245:34807;rport;branch=z9hG4bK313NH3rXtBg3c Max-Forwards: 70 From: ;tag=eHD3B5ZSQ4QUN To: Call-ID: 085024fb-a208-4f31-a77c-e10fc8bffd38 CSeq: 14180125 REGISTER Contact: Expires: 3600 User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Authorization: Digest username="1001", realm="dev-phones.sip.swire.io", nonce="XgoP6l4KDr6xrgdYbJtU2pEFLHrYoDKq", algorithm=MD5, uri="sip:dev-phones.sip.swire.io;transport=udp", response="8cddcd08bfcaa6a7ffce89f39a857d6d" Content-Length: 0 recv 488 bytes from udp/[190.102.98.218]:5060 at 20:26:50.365628: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 139.59.81.245:34807;rport=34807;branch=z9hG4bK313NH3rXtBg3c;received=139.59.81.245 From: ;tag=eHD3B5ZSQ4QUN To: ;tag=2557f8e108d5866fc8727054f77f98a6.d3ff Call-ID: 085024fb-a208-4f31-a77c-e10fc8bffd38 CSeq: 14180125 REGISTER WWW-Authenticate: Digest realm="dev-phones.sip.swire.io", nonce="XgoRXl4KEDJuk03oJMEgnRsyN10hG3B/" Server: SignalWire Proxy Content-Length: 0 send 868 bytes to udp/[190.102.98.218]:5060 at 20:26:50.365858: ------------------------------------------------------------------------ REGISTER sip:dev-phones.sip.swire.io;transport=udp SIP/2.0 Via: SIP/2.0/UDP 139.59.81.245:34807;rport;branch=z9hG4bK4aXeKy90Qm6Nr Max-Forwards: 70 From: ;tag=eHD3B5ZSQ4QUN To: Call-ID: 085024fb-a208-4f31-a77c-e10fc8bffd38 CSeq: 14180126 REGISTER Contact: Expires: 3600 User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Authorization: Digest username="1001", realm="dev-phones.sip.swire.io", nonce="XgoRXl4KEDJuk03oJMEgnRsyN10hG3B/", algorithm=MD5, uri="sip:dev-phones.sip.swire.io;transport=udp", response="e4b3214f20ae27ff94b4739f032a7452" Content-Length: 0 recv 486 bytes from udp/[190.102.98.218]:5060 at 20:26:50.683812: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 139.59.81.245:34807;rport=34807;branch=z9hG4bK4aXeKy90Qm6Nr;received=139.59.81.245 From: ;tag=eHD3B5ZSQ4QUN To: ;tag=2557f8e108d5866fc8727054f77f98a6.9081 Call-ID: 085024fb-a208-4f31-a77c-e10fc8bffd38 CSeq: 14180126 REGISTER Contact: ;expires=600 Server: SignalWire Proxy Content-Length: 0 2019-12-30 20:26:50.665511 [DEBUG] sofia_reg.c:2457 Changing expire time to 600 by request of proxy sip:dev-phones.sip.swire.io 2019-12-30 20:26:58.185492 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3 EXECUTE [depth=0] sofia/external/+16503820000@sip.signalwire.com hangup() 2019-12-30 20:26:58.185492 [NOTICE] mod_dptools.c:1380 Hangup sofia/external/+16503820000@sip.signalwire.com [CS_EXECUTE] [NORMAL_CLEARING] 2019-12-30 20:26:58.185492 [DEBUG] switch_core_session.c:2905 sofia/external/+16503820000@sip.signalwire.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:651 (sofia/external/+16503820000@sip.signalwire.com) State EXECUTE going to sleep 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_HANGUP (Cur 1 Tot 61) 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:848 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change EARLY -> HANGUP 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+16503820000@sip.signalwire.com) State HANGUP 2019-12-30 20:26:58.185492 [DEBUG] mod_sofia.c:460 Channel sofia/external/+16503820000@sip.signalwire.com hanging up, cause: NORMAL_CLEARING 2019-12-30 20:26:58.185492 [DEBUG] mod_sofia.c:605 Responding to INVITE with: 480 send 946 bytes to udp/[139.59.34.94]:5060 at 20:26:58.204805: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bK5fde.c1f2cb88d60d5b878a0fd3b9dfd4a691.0;i=804 Via: SIP/2.0/TLS 138.68.46.209:35181;received=138.68.46.209;rport=43634;branch=z9hG4bK105m2Nj6ym9yj Max-Forwards: 63 From: "CALIFORNIA " ;tag=grmN85UvDXrgH To: ;tag=c03a1gS30FmcH Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 CSeq: 14305105 INVITE User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 X-FS-Display-Name: 1001 X-FS-Display-Number: sip:1001@shashi-fs-12345.sip.signalwire.com P-Asserted-Identity: "1001" 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:60 sofia/external/+16503820000@sip.signalwire.com Standard HANGUP, cause: NORMAL_CLEARING 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+16503820000@sip.signalwire.com) State HANGUP going to sleep 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:620 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_HANGUP -> CS_REPORTING 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_REPORTING (Cur 1 Tot 61) 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:936 (sofia/external/+16503820000@sip.signalwire.com) State REPORTING 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:174 sofia/external/+16503820000@sip.signalwire.com Standard REPORTING, cause: NORMAL_CLEARING 2019-12-30 20:26:58.185492 [DEBUG] switch_core_state_machine.c:936 (sofia/external/+16503820000@sip.signalwire.com) State REPORTING going to sleep 2019-12-30 20:26:58.205480 [DEBUG] switch_core_state_machine.c:611 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_REPORTING -> CS_DESTROY 2019-12-30 20:26:58.205480 [DEBUG] switch_core_session.c:1726 Session 61 (sofia/external/+16503820000@sip.signalwire.com) Locked, Waiting on external entities 2019-12-30 20:26:58.205480 [NOTICE] switch_core_session.c:1744 Session 61 (sofia/external/+16503820000@sip.signalwire.com) Ended 2019-12-30 20:26:58.205480 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/+16503820000@sip.signalwire.com [CS_DESTROY] 2019-12-30 20:26:58.205480 [DEBUG] switch_core_state_machine.c:739 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_DESTROY (Cur 0 Tot 61) 2019-12-30 20:26:58.205480 [DEBUG] switch_core_state_machine.c:749 (sofia/external/+16503820000@sip.signalwire.com) State DESTROY 2019-12-30 20:26:58.205480 [DEBUG] mod_sofia.c:365 sofia/external/+16503820000@sip.signalwire.com SOFIA DESTROY 2019-12-30 20:26:58.205480 [DEBUG] switch_core_state_machine.c:181 sofia/external/+16503820000@sip.signalwire.com Standard DESTROY 2019-12-30 20:26:58.205480 [DEBUG] switch_core_state_machine.c:749 (sofia/external/+16503820000@sip.signalwire.com) State DESTROY going to sleep recv 431 bytes from udp/[139.59.34.94]:5060 at 20:26:58.206341: ------------------------------------------------------------------------ ACK sip:1001@139.59.81.245:34807;transport=udp;gw=signalwire_prod SIP/2.0 Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bK5fde.c1f2cb88d60d5b878a0fd3b9dfd4a691.0;i=804 Max-Forwards: 63 From: "CALIFORNIA " ;tag=grmN85UvDXrgH To: ;tag=c03a1gS30FmcH Call-ID: ff90d235-c41e-4281-8433-94c793ec1147 CSeq: 14305105 ACK Content-Length: 0 recv 1796 bytes from udp/[139.59.34.94]:5060 at 20:27:01.753021: ------------------------------------------------------------------------ INVITE sip:1001@139.59.81.245:34807;transport=udp;gw=signalwire_prod SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 Via: SIP/2.0/TLS 138.197.101.1:35181;received=138.197.101.1;rport=54404;branch=z9hG4bKtt6HyF6BXDgXa Max-Forwards: 63 From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 INVITE Contact: User-Agent: SignalWire STACK Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Session-Expires: 600;refresher=uac Min-SE: 90 Privacy: none Content-Type: application/sdp Content-Disposition: session Content-Length: 497 P-SRC-IP: 147.75.65.192 X-Relay-Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 X-CID: 1900329890_117407016@23.29.21.120 X-FS-Support: update_display,send_info P-Asserted-Identity: "Shashi Kumar " v=0 o=SignalWire-STACK 1577700661 1577700662 IN IP4 138.197.101.1 s=SignalWire-STACK c=IN IP4 138.197.101.1 t=0 0 m=audio 17160 RTP/SAVP 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=crypto:1 AEAD_AES_256_GCM_8 inline:acuqqtV88Pbn3PRnLXLyWXi89MALBoqIM6APKwvN29eVoPoas3rsA/CKwpM= a=ptime:20 m=audio 17160 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 2019-12-30 20:27:01.745508 [NOTICE] switch_channel.c:1118 New Channel sofia/external/+16503820000@sip.signalwire.com [13521b49-a0cb-43e8-a832-2fa8f3d4515c] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_NEW (Cur 1 Tot 62) 2019-12-30 20:27:01.745508 [DEBUG] sofia.c:10243 sofia/external/+16503820000@sip.signalwire.com receiving invite from 139.59.34.94:5060 version: 20.19.6 -release-14-2b31de9 64bit 2019-12-30 20:27:01.745508 [DEBUG] sofia.c:7290 Channel sofia/external/+16503820000@sip.signalwire.com entering state [received][100] 2019-12-30 20:27:01.745508 [DEBUG] sofia.c:7300 Remote SDP: v=0 o=SignalWire-STACK 1577700661 1577700662 IN IP4 138.197.101.1 s=SignalWire-STACK c=IN IP4 138.197.101.1 t=0 0 m=audio 17160 RTP/SAVP 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=crypto:1 AEAD_AES_256_GCM_8 inline:acuqqtV88Pbn3PRnLXLyWXi89MALBoqIM6APKwvN29eVoPoas3rsA/CKwpM= a=ptime:20 m=audio 17160 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 2019-12-30 20:27:01.745508 [DEBUG] sofia.c:7703 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_NEW -> CS_INIT 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:604 (sofia/external/+16503820000@sip.signalwire.com) State NEW 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_INIT (Cur 1 Tot 62) 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+16503820000@sip.signalwire.com) State INIT 2019-12-30 20:27:01.745508 [DEBUG] mod_sofia.c:93 sofia/external/+16503820000@sip.signalwire.com SOFIA INIT 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:40 sofia/external/+16503820000@sip.signalwire.com Standard INIT 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_INIT -> CS_ROUTING 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+16503820000@sip.signalwire.com) State INIT going to sleep 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_ROUTING (Cur 1 Tot 62) 2019-12-30 20:27:01.745508 [DEBUG] switch_channel.c:2332 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change DOWN -> RINGING 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+16503820000@sip.signalwire.com) State ROUTING send 412 bytes to udp/[139.59.34.94]:5060 at 20:27:01.755403: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 INVITE User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit Content-Length: 0 2019-12-30 20:27:01.745508 [DEBUG] mod_sofia.c:154 sofia/external/+16503820000@sip.signalwire.com SOFIA ROUTING 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:236 sofia/external/+16503820000@sip.signalwire.com Standard ROUTING 2019-12-30 20:27:01.745508 [INFO] mod_dialplan_xml.c:637 Processing Shashi Kumar <+16503820000>->1001 in context public Dialplan: sofia/external/+16503820000@sip.signalwire.com parsing [public->lua-env-hangup-hook-test] continue=false Dialplan: sofia/external/+16503820000@sip.signalwire.com Regex (PASS) [lua-env-hangup-hook-test] destination_number(1001) =~ /^(.*)$/ break=on-false Dialplan: sofia/external/+16503820000@sip.signalwire.com Action pre_answer() Dialplan: sofia/external/+16503820000@sip.signalwire.com Action playback(/usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3) Dialplan: sofia/external/+16503820000@sip.signalwire.com Action hangup() 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:287 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_ROUTING -> CS_EXECUTE 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+16503820000@sip.signalwire.com) State ROUTING going to sleep 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_EXECUTE (Cur 1 Tot 62) 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:651 (sofia/external/+16503820000@sip.signalwire.com) State EXECUTE 2019-12-30 20:27:01.745508 [DEBUG] mod_sofia.c:209 sofia/external/+16503820000@sip.signalwire.com SOFIA EXECUTE 2019-12-30 20:27:01.745508 [DEBUG] switch_core_state_machine.c:329 sofia/external/+16503820000@sip.signalwire.com Standard EXECUTE EXECUTE [depth=0] sofia/external/+16503820000@sip.signalwire.com pre_answer() 2019-12-30 20:27:01.745508 [INFO] mod_dptools.c:1477 Sending early media 2019-12-30 20:27:01.745508 [WARNING] switch_core_media.c:5475 Received invite with SAVP but secure media is administratively disabled 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5648 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5593 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5509 Set telephone-event payload to 101@8000 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:3837 Set Codec sofia/external/+16503820000@sip.signalwire.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2019-12-30 20:27:01.745508 [DEBUG] switch_core_codec.c:111 sofia/external/+16503820000@sip.signalwire.com Original read codec set to PCMU:0 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5852 Set telephone-event payload to 101@8000 2019-12-30 20:27:01.745508 [DEBUG] switch_core_media.c:5910 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf send payload to 101 recv payload to 101 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:8109 STUN Success [139.59.81.245]:[21506] 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:8113 STUN Not Required ip and port match. [139.59.81.245]:[21506] 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:8682 AUDIO RTP [sofia/external/+16503820000@sip.signalwire.com] 139.59.81.245 port 21506 -> 138.197.101.1 port 17160 codec: 0 ms: 20 2019-12-30 20:27:01.985500 [DEBUG] switch_rtp.c:4496 Starting timer [soft] 160 bytes per 20ms 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:8996 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf send payload to 101 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:9003 sofia/external/+16503820000@sip.signalwire.com Set 2833 dtmf receive payload to 101 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:9026 sofia/external/+16503820000@sip.signalwire.com Set rtp dtmf delay to 40 2019-12-30 20:27:01.985500 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/+16503820000@sip.signalwire.com! 2019-12-30 20:27:01.985500 [DEBUG] switch_channel.c:3565 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change RINGING -> EARLY 2019-12-30 20:27:01.985500 [DEBUG] switch_core_media.c:8664 Audio params are unchanged for sofia/external/+16503820000@sip.signalwire.com. 2019-12-30 20:27:01.985500 [DEBUG] mod_sofia.c:2600 Ring SDP: v=0 o=FreeSWITCH 1577696315 1577696316 IN IP4 139.59.81.245 s=FreeSWITCH c=IN IP4 139.59.81.245 t=0 0 m=audio 21506 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 1438 bytes to udp/[139.59.34.94]:5060 at 20:27:02.004887: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 Via: SIP/2.0/TLS 138.197.101.1:35181;received=138.197.101.1;rport=54404;branch=z9hG4bKtt6HyF6BXDgXa Record-Route: Record-Route: From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: ;tag=D9v32Ba7XraZc Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit 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-Type: application/sdp Content-Disposition: session Content-Length: 245 X-FS-Display-Name: 1001 X-FS-Display-Number: sip:1001@shashi-fs-12345.sip.signalwire.com X-FS-Support: update_display,send_info P-Asserted-Identity: "1001" v=0 o=FreeSWITCH 1577696315 1577696316 IN IP4 139.59.81.245 s=FreeSWITCH c=IN IP4 139.59.81.245 t=0 0 m=audio 0 RTP/SAVP 19 m=audio 21506 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2019-12-30 20:27:01.985500 [DEBUG] sofia.c:7290 Channel sofia/external/+16503820000@sip.signalwire.com entering state [early][183] EXECUTE [depth=0] sofia/external/+16503820000@sip.signalwire.com playback(/usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3) 2019-12-30 20:27:02.005478 [DEBUG] switch_ivr_play_say.c:1492 Codec Activated L16@8000hz 1 channels 20ms recv 469 bytes from udp/[139.59.34.94]:5060 at 20:27:02.976556: ------------------------------------------------------------------------ CANCEL sip:1001@139.59.81.245:34807;transport=udp;gw=signalwire_prod SIP/2.0 Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 Max-Forwards: 63 From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 CANCEL Content-Length: 0 Reason: SIP;cause=487;text="ORIGINATOR_CANCEL" send 359 bytes to udp/[139.59.34.94]:5060 at 20:27:02.976703: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: ;tag=D9v32Ba7XraZc Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 CANCEL Content-Length: 0 send 712 bytes to udp/[139.59.34.94]:5060 at 20:27:02.976825: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 Via: SIP/2.0/TLS 138.197.101.1:35181;received=138.197.101.1;rport=54404;branch=z9hG4bKtt6HyF6BXDgXa From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: ;tag=D9v32Ba7XraZc Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 INVITE User-Agent: FreeSWITCH-mod_sofia/20.19.6-release-14-2b31de9~64bit 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 433 bytes from udp/[139.59.34.94]:5060 at 20:27:02.977502: ------------------------------------------------------------------------ ACK sip:1001@139.59.81.245:34807;transport=udp;gw=signalwire_prod SIP/2.0 Via: SIP/2.0/UDP 139.59.34.94:5060;branch=z9hG4bKb996.0826543676554cc829e0af113fa8a7b6.0;i=904 Max-Forwards: 63 From: "Shashi Kumar " ;tag=BH0rXK5gg6BZc To: ;tag=D9v32Ba7XraZc Call-ID: ab67b548-c6cc-46ee-bb57-9bd9eb1c9226 CSeq: 14305118 ACK Content-Length: 0 2019-12-30 20:27:02.965492 [DEBUG] sofia.c:7290 Channel sofia/external/+16503820000@sip.signalwire.com entering state [terminated][487] 2019-12-30 20:27:02.965492 [NOTICE] sofia.c:8523 Hangup sofia/external/+16503820000@sip.signalwire.com [CS_EXECUTE] [ORIGINATOR_CANCEL] 2019-12-30 20:27:02.965492 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/src/backup/freeswitch-advantage/clients/flex/Sound_of_phone_ringing2.mp3 2019-12-30 20:27:02.965492 [DEBUG] switch_core_session.c:2905 sofia/external/+16503820000@sip.signalwire.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:651 (sofia/external/+16503820000@sip.signalwire.com) State EXECUTE going to sleep 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_HANGUP (Cur 1 Tot 62) 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:848 (sofia/external/+16503820000@sip.signalwire.com) Callstate Change EARLY -> HANGUP 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+16503820000@sip.signalwire.com) State HANGUP 2019-12-30 20:27:02.965492 [DEBUG] mod_sofia.c:460 Channel sofia/external/+16503820000@sip.signalwire.com hanging up, cause: ORIGINATOR_CANCEL 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:60 sofia/external/+16503820000@sip.signalwire.com Standard HANGUP, cause: ORIGINATOR_CANCEL 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+16503820000@sip.signalwire.com) State HANGUP going to sleep 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:620 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_HANGUP -> CS_REPORTING 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_REPORTING (Cur 1 Tot 62) 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:936 (sofia/external/+16503820000@sip.signalwire.com) State REPORTING 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:174 sofia/external/+16503820000@sip.signalwire.com Standard REPORTING, cause: ORIGINATOR_CANCEL 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:936 (sofia/external/+16503820000@sip.signalwire.com) State REPORTING going to sleep 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:611 (sofia/external/+16503820000@sip.signalwire.com) State Change CS_REPORTING -> CS_DESTROY 2019-12-30 20:27:02.965492 [DEBUG] switch_core_session.c:1726 Session 62 (sofia/external/+16503820000@sip.signalwire.com) Locked, Waiting on external entities 2019-12-30 20:27:02.965492 [NOTICE] switch_core_session.c:1744 Session 62 (sofia/external/+16503820000@sip.signalwire.com) Ended 2019-12-30 20:27:02.965492 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/+16503820000@sip.signalwire.com [CS_DESTROY] 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:739 (sofia/external/+16503820000@sip.signalwire.com) Running State Change CS_DESTROY (Cur 0 Tot 62) 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:749 (sofia/external/+16503820000@sip.signalwire.com) State DESTROY 2019-12-30 20:27:02.965492 [DEBUG] mod_sofia.c:365 sofia/external/+16503820000@sip.signalwire.com SOFIA DESTROY 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:181 sofia/external/+16503820000@sip.signalwire.com Standard DESTROY 2019-12-30 20:27:02.965492 [DEBUG] switch_core_state_machine.c:749 (sofia/external/+16503820000@sip.signalwire.com) State DESTROY going to sleep