On Mon, Sep 30, 2019 at 4:10 PM Ciprian Dosoftei <ciprian.dosoftei@gmail.com> wrote:
Hi Nathan,
If you could provide the full SIP trace for a sample, that would be great.
Sure, see below. While the Contact header is indeed typically pointing back at the standard
SIP IP/port combination (i.e. non-WebSocket), most JS SIP client library gracefully work around it (even without rport hints).
So this is a know issue?
Do you use a public stack for the client portion or a implementation?
We are using SIP.js on the web side and Libre SIP stack for iOS and Android, both have issues with this bug. +OK log level [7] freeswitch@as1-east> sofia global siptrace on +OK Global siptrace on recv 2642 bytes from wss/[50.246.121.173]:34010 at 20:27:36.440748: ------------------------------------------------------------------------ INVITE sip:nathan@stage.illumy1.com SIP/2.0 Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK6235908 To: <sip:nathan@stage.illumy1.com> From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 CSeq: 1 INVITE Call-ID: reo4dv21qm4aauclal7r Max-Forwards: 70 X-Foo: true Contact: <sip:0s9riicj@vg5qpm92h7dm.invalid;transport=ws;ob> Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Supported: outbound User-Agent: beth@stage.illumy1.com Content-Type: application/sdp Content-Length: 2108 v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=sendrecv a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.431835 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/beth@stage.illumy1.com [59f602c8-5c38-4c8b-984f-7f09197e9fa3] 2019-09-30 20:27:36.431835 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/beth@stage.illumy1.com) Running State Change CS_NEW (Cur 3 Tot 925) 2019-09-30 20:27:36.431835 [DEBUG] sofia.c:10242 sofia/internal/ beth@stage.illumy1.com receiving invite from 50.246.121.173:34010 version: 1.10.0 -release 64bit 2019-09-30 20:27:36.431835 [DEBUG] sofia.c:10336 verifying acl "internal" for ip/port 50.246.121.173:0. 2019-09-30 20:27:36.431835 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/beth@stage.illumy1.com) State NEW send 853 bytes to wss/[50.246.121.173]:34010 at 20:27:36.445754: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK6235908;received=50.246.121.173;rport=34010 From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 To: <sip:nathan@stage.illumy1.com>;tag=Up8tp3554QHpj Call-ID: reo4dv21qm4aauclal7r CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.10.0-release~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="stage.illumy1.com", nonce="921a7927-e0ba-4eb3-8532-cb4c1490721c", algorithm=MD5, qop="auth" Content-Length: 0 2019-09-30 20:27:36.431835 [DEBUG] sofia.c:2426 detaching session 59f602c8-5c38-4c8b-984f-7f09197e9fa3 recv 316 bytes from wss/[50.246.121.173]:34010 at 20:27:36.505757: ------------------------------------------------------------------------ ACK sip:nathan@stage.illumy1.com SIP/2.0 Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK6235908 To: <sip:nathan@stage.illumy1.com>;tag=Up8tp3554QHpj From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 Call-ID: reo4dv21qm4aauclal7r CSeq: 1 ACK Max-Forwards: 70 Content-Length: 0 recv 2902 bytes from wss/[50.246.121.173]:34010 at 20:27:36.505833: ------------------------------------------------------------------------ INVITE sip:nathan@stage.illumy1.com SIP/2.0 Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK9166577 To: <sip:nathan@stage.illumy1.com> From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 CSeq: 2 INVITE Call-ID: reo4dv21qm4aauclal7r Max-Forwards: 70 Proxy-Authorization: Digest algorithm=MD5, username="beth", realm=" stage.illumy1.com", nonce="921a7927-e0ba-4eb3-8532-cb4c1490721c", uri=" sip:nathan@stage.illumy1.com", response="68b33afa613ebdf80f0694bc454dac65", qop=auth, cnonce="k3s2qg42vh0i", nc=00000001 X-Foo: true Contact: <sip:0s9riicj@vg5qpm92h7dm.invalid;transport=ws;ob> Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Supported: outbound User-Agent: beth@stage.illumy1.com Content-Type: application/sdp Content-Length: 2108 v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=sendrecv a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.491837 [DEBUG] sofia.c:2535 Re-attaching to session 59f602c8-5c38-4c8b-984f-7f09197e9fa3 2019-09-30 20:27:36.511840 [DEBUG] sofia.c:10242 sofia/internal/ beth@stage.illumy1.com receiving invite from 50.246.121.173:34010 version: 1.10.0 -release 64bit 2019-09-30 20:27:36.511840 [DEBUG] sofia.c:10336 verifying acl "internal" for ip/port 50.246.121.173:0. 2019-09-30 20:27:36.531844 [DEBUG] sofia.c:11432 Setting NAT mode based on via received 2019-09-30 20:27:36.531844 [DEBUG] sofia.c:7289 Channel sofia/internal/ beth@stage.illumy1.com entering state [received][100] 2019-09-30 20:27:36.531844 [DEBUG] sofia.c:7299 Remote SDP: v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.531844 [DEBUG] sofia.c:7702 (sofia/internal/ beth@stage.illumy1.com) State Change CS_NEW -> CS_INIT 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/beth@stage.illumy1.com) Running State Change CS_INIT (Cur 3 Tot 925) 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/beth@stage.illumy1.com) State INIT 2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:93 sofia/internal/ beth@stage.illumy1.com SOFIA INIT 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:40 sofia/internal/beth@stage.illumy1.com Standard INIT 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/beth@stage.illumy1.com) State Change CS_INIT -> CS_ROUTING 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/beth@stage.illumy1.com) State INIT going to sleep 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/beth@stage.illumy1.com) Running State Change CS_ROUTING (Cur 3 Tot 925) 2019-09-30 20:27:36.531844 [DEBUG] switch_channel.c:2332 (sofia/internal/ beth@stage.illumy1.com) Callstate Change DOWN -> RINGING 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/beth@stage.illumy1.com) State ROUTING 2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:154 sofia/internal/ beth@stage.illumy1.com SOFIA ROUTING 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:236 sofia/internal/beth@stage.illumy1.com Standard ROUTING 2019-09-30 20:27:36.531844 [INFO] mod_dialplan_xml.c:637 Processing beth@stage.illumy1.com <beth>->nathan in context default send 352 bytes to wss/[50.246.121.173]:34010 at 20:27:36.543879: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK9166577;received=50.246.121.173;rport=34010 From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 To: <sip:nathan@stage.illumy1.com> Call-ID: reo4dv21qm4aauclal7r CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.10.0-release~64bit Content-Length: 0 Dialplan: sofia/internal/beth@stage.illumy1.com parsing [default->global] continue=true Dialplan: sofia/internal/beth@stage.illumy1.com Absolute Condition [global] Dialplan: sofia/internal/beth@stage.illumy1.com Action info() Dialplan: sofia/internal/beth@stage.illumy1.com parsing [default->Local_Users] continue=false Dialplan: sofia/internal/beth@stage.illumy1.com Regex (PASS) [Local_Users] destination_number(nathan) =~ /((?!^\d+$)^[a-zA-Z0-9_\-\.]+$)$/ break=on-false Dialplan: sofia/internal/beth@stage.illumy1.com Action set(continue_on_fail=false) Dialplan: sofia/internal/beth@stage.illumy1.com Action set(hangup_after_bridge=true) Dialplan: sofia/internal/beth@stage.illumy1.com Action set(bypass_media=true) Dialplan: sofia/internal/beth@stage.illumy1.com Action lua(endpoint_lookup.lua) Dialplan: sofia/internal/beth@stage.illumy1.com Action set(call_timeout=20) Dialplan: sofia/internal/beth@stage.illumy1.com Action bridge(${dial_to_string}) Dialplan: sofia/internal/beth@stage.illumy1.com Action set(bypass_media=false) Dialplan: sofia/internal/beth@stage.illumy1.com Action answer() Dialplan: sofia/internal/beth@stage.illumy1.com Action sleep(1000) Dialplan: sofia/internal/beth@stage.illumy1.com Action voicemail(${voicemail_string}) 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/beth@stage.illumy1.com) State Change CS_ROUTING -> CS_EXECUTE 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/beth@stage.illumy1.com) State ROUTING going to sleep 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/beth@stage.illumy1.com) Running State Change CS_EXECUTE (Cur 3 Tot 925) 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/beth@stage.illumy1.com) State EXECUTE 2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:209 sofia/internal/ beth@stage.illumy1.com SOFIA EXECUTE 2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:329 sofia/internal/beth@stage.illumy1.com Standard EXECUTE EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com info() 2019-09-30 20:27:36.531844 [INFO] mod_dptools.c:1885 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-Call-State: [RINGING] Channel-State-Number: [4] Channel-Name: [sofia/internal/beth@stage.illumy1.com] Unique-ID: [59f602c8-5c38-4c8b-984f-7f09197e9fa3] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [beth@stage.illumy1.com] Channel-Call-UUID: [59f602c8-5c38-4c8b-984f-7f09197e9fa3] Answer-State: [ringing] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [beth] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [beth@stage.illumy1.com] Caller-Caller-ID-Number: [beth] Caller-Orig-Caller-ID-Name: [beth@stage.illumy1.com] Caller-Orig-Caller-ID-Number: [beth] Caller-Network-Addr: [50.246.121.173] Caller-ANI: [beth] Caller-Destination-Number: [nathan] Caller-Unique-ID: [59f602c8-5c38-4c8b-984f-7f09197e9fa3] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/beth@stage.illumy1.com] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1569875256531844] Caller-Channel-Created-Time: [1569875256531844] Caller-Channel-Answered-Time: [0] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [0] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] variable_direction: [inbound] variable_uuid: [59f602c8-5c38-4c8b-984f-7f09197e9fa3] variable_session_id: [925] variable_sip_from_user: [beth] variable_sip_from_uri: [beth@stage.illumy1.com] variable_sip_from_host: [stage.illumy1.com] variable_video_media_flow: [disabled] variable_audio_media_flow: [disabled] variable_text_media_flow: [disabled] variable_channel_name: [sofia/internal/beth@stage.illumy1.com] variable_sip_call_id: [reo4dv21qm4aauclal7r] variable_sip_local_network_addr: [18.211.78.106] variable_sip_network_ip: [50.246.121.173] variable_sip_network_port: [34010] variable_sip_invite_stamp: [1569875256511840] variable_sip_received_ip: [50.246.121.173] variable_sip_received_port: [34010] variable_sip_via_protocol: [wss] variable_sip_authorized: [true] variable_Event-Name: [REQUEST_PARAMS] variable_Core-UUID: [7e617e4b-996a-445f-a4d4-c6fc5db9b2cf] variable_FreeSWITCH-Hostname: [as1-east] variable_FreeSWITCH-Switchname: [as1-east] variable_FreeSWITCH-IPv4: [10.0.0.237] variable_FreeSWITCH-IPv6: [::1] variable_Event-Date-Local: [2019-09-30 20:27:36] variable_Event-Date-GMT: [Mon, 30 Sep 2019 20:27:36 GMT] variable_Event-Date-Timestamp: [1569875256511840] variable_Event-Calling-File: [sofia.c] variable_Event-Calling-Function: [sofia_handle_sip_i_invite] variable_Event-Calling-Line-Number: [10504] variable_Event-Sequence: [152629] variable_sip_number_alias: [beth] variable_sip_auth_username: [beth] variable_sip_auth_realm: [stage.illumy1.com] variable_number_alias: [beth] variable_requested_user_name: [beth] variable_requested_domain_name: [stage.illumy1.com] variable_user_context: [default] variable_effective_caller_id_name: [Beth User] variable_effective_caller_id_number: [beth] variable_outbound_caller_id_name: [Beth User] variable_user_name: [beth] variable_domain_name: [stage.illumy1.com] variable_sip_from_user_stripped: [beth] variable_sip_from_tag: [36ov91agi3] variable_sofia_profile_name: [internal] variable_sofia_profile_url: [sip:mod_sofia@18.211.78.106:5060] variable_recovery_profile_name: [internal] variable_sip_full_via: [SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK9166577;received=50.246.121.173;rport=34010] variable_sip_from_display: [beth@stage.illumy1.com] variable_sip_full_from: ["beth@stage.illumy1.com" < sip:beth@stage.illumy1.com>;tag=36ov91agi3] variable_sip_full_to: [<sip:nathan@stage.illumy1.com>] variable_sip_allow: [ACK, CANCEL, INVITE, MESSAGE, BYE, OPTIONS, INFO, NOTIFY, REFER] variable_sip_req_user: [nathan] variable_sip_req_uri: [nathan@stage.illumy1.com] variable_sip_req_host: [stage.illumy1.com] variable_sip_to_user: [nathan] variable_sip_to_uri: [nathan@stage.illumy1.com] variable_sip_to_host: [stage.illumy1.com] variable_sip_contact_params: [transport=ws;ob] variable_sip_contact_user: [0s9riicj] variable_sip_contact_uri: [0s9riicj@vg5qpm92h7dm.invalid] variable_sip_contact_host: [vg5qpm92h7dm.invalid] variable_rtp_use_codec_string: [OPUS,PCMU,VP8] variable_sip_user_agent: [beth@stage.illumy1.com] variable_sip_via_host: [vg5qpm92h7dm.invalid] variable_sip_via_rport: [34010] variable_max_forwards: [70] variable_presence_id: [beth@stage.illumy1.com] variable_sip_h_X-Foo: [true] variable_sip_nat_detected: [true] variable_switch_r_sdp: [v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 ] variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c ,CORE_PCM_MODULE.PCMU@8000h@20i@64000b] variable_endpoint_disposition: [DELAYED NEGOTIATION] variable_DP_MATCH: [ARRAY::nathan|:nathan] variable_call_uuid: [59f602c8-5c38-4c8b-984f-7f09197e9fa3] variable_current_application: [info] EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com set(continue_on_fail=false) 2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/ beth@stage.illumy1.com [continue_on_fail]=[false] EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com set(hangup_after_bridge=true) 2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/ beth@stage.illumy1.com [hangup_after_bridge]=[true] EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com set(bypass_media=true) 2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/ beth@stage.illumy1.com [bypass_media]=[true] EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com lua(endpoint_lookup.lua) 2019-09-30 20:27:36.591836 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable('voicemail_string', 'default stage.illumy1.com nathan') 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 SEARCH QUERY: SELECT server_host FROM sip_registrations WHERE sip_user = 'nathan' AND sip_host = 'stage.illumy1.com' AND ping_status = 'Reachable'; 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 FOUND AT HOST: 10.0.0.12 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 FOUND AT HOST: 10.0.0.237 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 User's nathan@stage.illumy1.com toll_allow value is <voicemail> 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 Voicemail enabled 2019-09-30 20:27:36.591836 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable('continue_on_fail', 'true') 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 ADDING HOST: 10.0.0.12 TO DIAL STRING 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 REMOTE REGISTERED USER! 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 ADDING HOST: 10.0.0.237 TO DIAL STRING 2019-09-30 20:27:36.591836 [INFO] switch_cpp.cpp:1443 LOCAL REGISTERED USER! 2019-09-30 20:27:36.591836 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable('dial_to_string', '[sip_h_X-voicemailed=true,sip_h_X-local-call=true,sip_invite_domain= stage.illumy1.com]sofia/external/nathan@10.0.0.12:5080,${sofia_contact( nathan@stage.illumy1.com)}') 2019-09-30 20:27:36.591836 [DEBUG] switch_cpp.cpp:1187 sofia/internal/ beth@stage.illumy1.com destroy/unlink session from object EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com set(call_timeout=20) 2019-09-30 20:27:36.591836 [DEBUG] mod_dptools.c:1672 SET sofia/internal/ beth@stage.illumy1.com [call_timeout]=[20] EXECUTE [depth=0] sofia/internal/beth@stage.illumy1.com bridge([sip_h_X-voicemailed=true,sip_h_X-local-call=true,sip_invite_domain= stage.illumy1.com]sofia/external/nathan@10.0.0.12:5080 ,sofia/internal/sip:j7fd3415@geutlen0uga7.invalid ;transport=ws;received=50.246.121.173:39318 ;fs_nat=yes;fs_path=sip%3Aj7fd3415%4050.246.121.173%3A39318%3Btransport%3Dwss,sofia/internal/sip:r6ucrocm@3val7ifjblg6.invalid ;transport=ws;received=50.246.121.173:34738 ;fs_nat=yes;fs_path=sip%3Ar6ucrocm%4050.246.121.173%3A34738%3Btransport%3Dwss) 2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables 2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:2757 Parsing session specific variables 2019-09-30 20:27:36.591836 [NOTICE] switch_channel.c:1118 New Channel sofia/external/nathan@10.0.0.12:5080 [971aae94-0463-4c9f-809d-10dfbcb265bc] 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:5096 (sofia/external/ nathan@10.0.0.12:5080) State Change CS_NEW -> CS_INIT 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/external/nathan@10.0.0.12:5080) Running State Change CS_INIT (Cur 4 Tot 926) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/external/nathan@10.0.0.12:5080) State INIT 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93 sofia/external/ nathan@10.0.0.12:5080 SOFIA INIT 2019-09-30 20:27:36.591836 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/j7fd3415@geutlen0uga7.invalid [83e36ab7-8275-4a5e-9afd-f9356da57b06] 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:5096 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State Change CS_NEW -> CS_INIT 2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618 sofia/external/ nathan@10.0.0.12:5080 sending invite version: 1.10.0 -release 64bit Local SDP: v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.591836 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/r6ucrocm@3val7ifjblg6.invalid [56c0cd2d-e19b-4c45-a278-81ed26d09636] 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:5096 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State Change CS_NEW -> CS_INIT send 2935 bytes to udp/[10.0.0.12]:5080 at 20:27:36.605793: ------------------------------------------------------------------------ INVITE sip:nathan@10.0.0.12:5080 SIP/2.0 Via: SIP/2.0/UDP 10.0.0.237:5080;rport;branch=z9hG4bKHmc9rvvg1aUeQ Max-Forwards: 69 From: "Beth User" <sip:beth@stage.illumy1.com>;tag=UXNaNXZpme5SD To: <sip:nathan@10.0.0.12:5080> Call-ID: 94fd528d-5e63-1238-2787-0251a831415e CSeq: 10383836 INVITE Contact: <sip:mod_sofia@10.0.0.237:5080> User-Agent: FreeSWITCH-mod_sofia/1.10.0-release~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 2097 X-Foo: true X-voicemailed: true X-local-call: true X-FS-Support: update_display,send_info Remote-Party-ID: "Beth User" <sip:beth@stage.illumy1.com
;party=calling;screen=yes;privacy=off
v=0 o=- 3923831751587036465 2 IN IP4 10.0.0.237 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:40 sofia/external/nathan@10.0.0.12:5080 Standard INIT 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48 (sofia/external/nathan@10.0.0.12:5080) State Change CS_INIT -> CS_ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/external/nathan@10.0.0.12:5080) State INIT going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/j7fd3415@geutlen0uga7.invalid) Running State Change CS_INIT (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/external/nathan@10.0.0.12:5080) Running State Change CS_ROUTING (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] sofia.c:7289 Channel sofia/external/ nathan@10.0.0.12:5080 entering state [calling][0] 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State INIT 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93 sofia/internal/j7fd3415@geutlen0uga7.invalid SOFIA INIT 2019-09-30 20:27:36.591836 [DEBUG] sofia.c:7289 Channel sofia/external/ nathan@10.0.0.12:5080 entering state [terminated][503] 2019-09-30 20:27:36.591836 [NOTICE] sofia.c:8522 Hangup sofia/external/ nathan@10.0.0.12:5080 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE] 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/external/nathan@10.0.0.12:5080) State ROUTING 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154 sofia/external/ nathan@10.0.0.12:5080 SOFIA ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/external/nathan@10.0.0.12:5080) State ROUTING going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/external/nathan@10.0.0.12:5080) Running State Change CS_HANGUP (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1587 sip:j7fd3415@50.246.121.173:39318;transport=wss Setting proxy route to sofia/internal/j7fd3415@geutlen0uga7.invalid 2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618 sofia/internal/j7fd3415@geutlen0uga7.invalid sending invite version: 1.10.0 -release 64bit Local SDP: v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:848 (sofia/external/nathan@10.0.0.12:5080) Callstate Change DOWN -> HANGUP 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:850 (sofia/external/nathan@10.0.0.12:5080) State HANGUP 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:460 Channel sofia/external/ nathan@10.0.0.12:5080 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:60 sofia/external/nathan@10.0.0.12:5080 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:850 (sofia/external/nathan@10.0.0.12:5080) State HANGUP going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:620 (sofia/external/nathan@10.0.0.12:5080) State Change CS_HANGUP -> CS_REPORTING 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/external/nathan@10.0.0.12:5080) Running State Change CS_REPORTING (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:936 (sofia/external/nathan@10.0.0.12:5080) State REPORTING 2019-09-30 20:27:36.591836 [DEBUG] mod_odbc_cdr.c:345 sql INSERT INTO cdr_table_both (CallId) VALUES ('971aae94-0463-4c9f-809d-10dfbcb265bc') 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:40 sofia/internal/j7fd3415@geutlen0uga7.invalid Standard INIT 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State Change CS_INIT -> CS_ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State INIT going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/j7fd3415@geutlen0uga7.invalid) Running State Change CS_ROUTING (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State ROUTING 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154 sofia/internal/j7fd3415@geutlen0uga7.invalid SOFIA ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State ROUTING going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/j7fd3415@geutlen0uga7.invalid) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State CONSUME_MEDIA 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/j7fd3415@geutlen0uga7.invalid) State CONSUME_MEDIA going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Running State Change CS_INIT (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State INIT 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93 sofia/internal/r6ucrocm@3val7ifjblg6.invalid SOFIA INIT 2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1587 sip:r6ucrocm@50.246.121.173:34738;transport=wss Setting proxy route to sofia/internal/r6ucrocm@3val7ifjblg6.invalid 2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618 sofia/internal/r6ucrocm@3val7ifjblg6.invalid sending invite version: 1.10.0 -release 64bit Local SDP: v=0 o=- 3923831751587036465 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:40 sofia/internal/r6ucrocm@3val7ifjblg6.invalid Standard INIT 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State Change CS_INIT -> CS_ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State INIT going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Running State Change CS_ROUTING (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State ROUTING 2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154 sofia/internal/r6ucrocm@3val7ifjblg6.invalid SOFIA ROUTING 2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State ROUTING going to sleep 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 928) 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State CONSUME_MEDIA 2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State CONSUME_MEDIA going to sleep 2019-09-30 20:27:36.591836 [DEBUG] mod_odbc_cdr.c:345 sql INSERT INTO cdr_table_b_leg (CallId, orig_id, term_id, ClientId) VALUES ('59f602c8-5c38-4c8b-984f-7f09197e9fa3', '971aae94-0463-4c9f-809d-10dfbcb265bc', '94fd528d-5e63-1238-2787-0251a831415e', '971aae94-0463-4c9f-809d-10dfbcb265bc') 2019-09-30 20:27:36.591836 [DEBUG] sofia.c:7289 Channel sofia/internal/j7fd3415@geutlen0uga7.invalid entering state [calling][0] send 3150 bytes to wss/[50.246.121.173]:34738 at 20:27:36.611364: ------------------------------------------------------------------------ INVITE sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738 SIP/2.0 Via: SIP/2.0/WSS 18.211.78.106:443;rport;branch=z9hG4bKye2ergXZB23jK Route: <sip:r6ucrocm@50.246.121.173:34738>;transport=wss Max-Forwards: 69 From: "Beth User" <sip:beth@18.211.78.106>;tag=yHm5UmrgvjmeN To: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738> Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e CSeq: 10383836 INVITE Contact: <sip:mod_sofia@18.211.78.106:5060> User-Agent: FreeSWITCH-mod_sofia/1.10.0-release~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 2097 X-Foo: true Remote-Party-ID: "Beth User" <sip:beth@18.211.78.106
;party=calling;screen=yes;privacy=off
v=0 o=- 3923831751587036465 2 IN IP4 10.0.0.237 s=- t=0 0 a=group:BUNDLE 0 a=msid-semantic: WMS DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc m=audio 61006 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 18.204.23.155 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:1978755251 1 udp 2122260223 10.88.65.80 34027 typ host generation 0 network-id 1 network-cost 10 a=candidate:3702450022 1 udp 1686052607 50.246.121.173 34027 typ srflx raddr 10.88.65.80 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:3425785639 1 udp 41885439 18.204.23.155 61006 typ relay raddr 50.246.121.173 rport 34027 generation 0 network-id 1 network-cost 10 a=candidate:997364803 1 tcp 1518280447 10.88.65.80 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:EVJX a=ice-pwd:ppoOZcwEGehOPKMM03ol7g5r a=ice-options:trickle a=fingerprint:sha-256 37:F4:29:14:94:6A:87:51:7E:44:81:FA:71:BF:22:D7:71:0C:02:93:49:61:36:3A:A6:AA:B5:34:2B:CA:1F:55 a=setup:actpass a=mid:0 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid a=extmap:4 urn:ietf:params:rtp-hdrext:sdes:rtp-stream-id a=extmap:5 urn:ietf:params:rtp-hdrext:sdes:repaired-rtp-stream-id a=msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=rtcp-mux a=rtcp-fb:111 transport-cc a=ssrc:767982924 cname:D8OaexP97luPw4OL a=ssrc:767982924 msid:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc 4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 a=ssrc:767982924 mslabel:DrxEOjCVvHNi3DtuKJs175ibnTtb2huY2WVc a=ssrc:767982924 label:4fdf8bec-c8e1-42d1-a872-db6864ef5ac2 2019-09-30 20:27:36.591836 [DEBUG] sofia.c:7289 Channel sofia/internal/r6ucrocm@3val7ifjblg6.invalid entering state [calling][0] 2019-09-30 20:27:36.611834 [DEBUG] switch_core_state_machine.c:174 sofia/external/nathan@10.0.0.12:5080 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2019-09-30 20:27:36.611834 [DEBUG] switch_core_state_machine.c:936 (sofia/external/nathan@10.0.0.12:5080) State REPORTING going to sleep 2019-09-30 20:27:36.611834 [DEBUG] switch_core_state_machine.c:611 (sofia/external/nathan@10.0.0.12:5080) State Change CS_REPORTING -> CS_DESTROY 2019-09-30 20:27:36.611834 [DEBUG] switch_core_session.c:1726 Session 926 (sofia/external/nathan@10.0.0.12:5080) Locked, Waiting on external entities recv 386 bytes from wss/[50.246.121.173]:34738 at 20:27:36.651849: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/WSS 18.211.78.106:443;rport;branch=z9hG4bKye2ergXZB23jK From: "Beth User" <sip:beth@18.211.78.106>;tag=yHm5UmrgvjmeN To: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738> CSeq: 10383836 INVITE Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e Supported: outbound User-Agent: nathan@stage.illumy1.com Content-Length: 0 recv 461 bytes from wss/[50.246.121.173]:34738 at 20:27:36.656498: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/WSS 18.211.78.106:443;rport;branch=z9hG4bKye2ergXZB23jK From: "Beth User" <sip:beth@18.211.78.106>;tag=yHm5UmrgvjmeN To: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738>;tag=9eibedbcg9 CSeq: 10383836 INVITE Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e Supported: outbound User-Agent: nathan@stage.illumy1.com Contact: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws> Content-Length: 0 2019-09-30 20:27:36.651842 [DEBUG] sofia.c:7289 Channel sofia/internal/r6ucrocm@3val7ifjblg6.invalid entering state [proceeding][180] 2019-09-30 20:27:36.651842 [NOTICE] sofia.c:7400 Ring-Ready sofia/internal/r6ucrocm@3val7ifjblg6.invalid! 2019-09-30 20:27:36.651842 [NOTICE] mod_sofia.c:2505 Ring-Ready sofia/internal/beth@stage.illumy1.com! send 760 bytes to wss/[50.246.121.173]:34010 at 20:27:36.666536: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK9166577;received=50.246.121.173;rport=34010 From: "beth@stage.illumy1.com" <sip:beth@stage.illumy1.com>;tag=36ov91agi3 To: <sip:nathan@stage.illumy1.com>;tag=vZ1Kryp91078D Call-ID: reo4dv21qm4aauclal7r CSeq: 2 INVITE Contact: <sip:nathan@18.211.78.106:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.10.0-release~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Length: 0 2019-09-30 20:27:36.651842 [DEBUG] switch_channel.c:3437 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Callstate Change DOWN -> RINGING 2019-09-30 20:27:36.651842 [DEBUG] sofia.c:7289 Channel sofia/internal/ beth@stage.illumy1.com entering state [early][180] 2019-09-30 20:27:36.651842 [NOTICE] switch_ivr_originate.c:553 Ring Ready sofia/internal/beth@stage.illumy1.com! recv 418 bytes from wss/[50.246.121.173]:34738 at 20:27:38.973706: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/WSS 18.211.78.106:443;rport;branch=z9hG4bKye2ergXZB23jK From: "Beth User" <sip:beth@18.211.78.106>;tag=yHm5UmrgvjmeN To: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738>;tag=9eibedbcg9 CSeq: 10383836 INVITE Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e Supported: outbound User-Agent: nathan@stage.illumy1.com Content-Length: 0 send 485 bytes to wss/[50.246.121.173]:34738 at 20:27:38.973840: ------------------------------------------------------------------------ ACK sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738 SIP/2.0 Via: SIP/2.0/WSS 18.211.78.106:443;rport;branch=z9hG4bKye2ergXZB23jK Route: <sip:r6ucrocm@50.246.121.173:34738>;transport=wss Max-Forwards: 69 From: "Beth User" <sip:beth@18.211.78.106>;tag=yHm5UmrgvjmeN To: <sip:r6ucrocm@3val7ifjblg6.invalid;transport=ws;received= 50.246.121.173:34738>;tag=9eibedbcg9 Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e CSeq: 10383836 ACK Content-Length: 0 2019-09-30 20:27:38.971902 [DEBUG] sofia.c:7289 Channel sofia/internal/r6ucrocm@3val7ifjblg6.invalid entering state [terminated][480] 2019-09-30 20:27:38.971902 [NOTICE] sofia.c:8522 Hangup sofia/internal/r6ucrocm@3val7ifjblg6.invalid [CS_CONSUME_MEDIA] [NO_USER_RESPONSE] 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Running State Change CS_HANGUP (Cur 6 Tot 928) 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Callstate Change RINGING -> HANGUP 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State HANGUP 2019-09-30 20:27:38.971902 [DEBUG] mod_sofia.c:460 Channel sofia/internal/r6ucrocm@3val7ifjblg6.invalid hanging up, cause: NO_USER_RESPONSE 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:60 sofia/internal/r6ucrocm@3val7ifjblg6.invalid Standard HANGUP, cause: NO_USER_RESPONSE 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State HANGUP going to sleep 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State Change CS_HANGUP -> CS_REPORTING 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Running State Change CS_REPORTING (Cur 6 Tot 928) 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State REPORTING 2019-09-30 20:27:38.971902 [DEBUG] mod_odbc_cdr.c:345 sql INSERT INTO cdr_table_both (CallId, TEST_id) VALUES ('56c0cd2d-e19b-4c45-a278-81ed26d09636', 'beth@18.211.78.106') 2019-09-30 20:27:38.971902 [DEBUG] mod_odbc_cdr.c:345 sql INSERT INTO cdr_table_b_leg (TelNumberFull, CallId, orig_id, CallerID, IP, term_id, ClientId) VALUES ('r6ucrocm', '59f602c8-5c38-4c8b-984f-7f09197e9fa3', '56c0cd2d-e19b-4c45-a278-81ed26d09636', 'beth', '50.246.121.173', '94fe2e19-5e63-1238-2787-0251a831415e', '56c0cd2d-e19b-4c45-a278-81ed26d09636') 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:174 sofia/internal/r6ucrocm@3val7ifjblg6.invalid Standard REPORTING, cause: NO_USER_RESPONSE 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State REPORTING going to sleep 2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) State Change CS_REPORTING -> CS_DESTROY 2019-09-30 20:27:38.971902 [DEBUG] switch_core_session.c:1726 Session 928 (sofia/internal/r6ucrocm@3val7ifjblg6.invalid) Locked, Waiting on external entities --
<> nathan stratton