[Freeswitch-users] SIP over WSS responding with 5060; transport=udp in Contact:

Tue Oct 1 03:48:01 UTC 2019

On Mon, Sep 30, 2019 at 4:10 PM Ciprian Dosoftei <ciprian.dosoftei at 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 at 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 at stage.illumy1.com SIP/2.0
Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK6235908
To: <sip:nathan at stage.illumy1.com>
From: "beth at stage.illumy1.com" <sip:beth at stage.illumy1.com>;tag=36ov91agi3
CSeq: 1 INVITE
Call-ID: reo4dv21qm4aauclal7r
Max-Forwards: 70
X-Foo: true
Contact: <sip:0s9riicj at vg5qpm92h7dm.invalid;transport=ws;ob>
Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER
Supported: outbound
User-Agent: beth at 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 at 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 at 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 at 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 at 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 at stage.illumy1.com" <sip:beth at stage.illumy1.com>;tag=36ov91agi3
To: <sip:nathan at 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 at stage.illumy1.com SIP/2.0
Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK6235908
To: <sip:nathan at stage.illumy1.com>;tag=Up8tp3554QHpj
From: "beth at stage.illumy1.com" <sip:beth at 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 at stage.illumy1.com SIP/2.0
Via: SIP/2.0/WSS vg5qpm92h7dm.invalid;branch=z9hG4bK9166577
To: <sip:nathan at stage.illumy1.com>
From: "beth at stage.illumy1.com" <sip:beth at 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 at stage.illumy1.com", response="68b33afa613ebdf80f0694bc454dac65",
qop=auth, cnonce="k3s2qg42vh0i", nc=00000001
X-Foo: true
Contact: <sip:0s9riicj at vg5qpm92h7dm.invalid;transport=ws;ob>
Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER
Supported: outbound
User-Agent: beth at 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 at 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 at 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 at 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 at 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 at stage.illumy1.com) State INIT
2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:93 sofia/internal/
beth at stage.illumy1.com SOFIA INIT
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:40
sofia/internal/beth at stage.illumy1.com Standard INIT
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/beth at 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 at 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 at 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 at stage.illumy1.com) Callstate Change DOWN -> RINGING
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:644
(sofia/internal/beth at stage.illumy1.com) State ROUTING
2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:154 sofia/internal/
beth at stage.illumy1.com SOFIA ROUTING
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:236
sofia/internal/beth at stage.illumy1.com Standard ROUTING
2019-09-30 20:27:36.531844 [INFO] mod_dialplan_xml.c:637 Processing
beth at 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 at stage.illumy1.com" <sip:beth at stage.illumy1.com>;tag=36ov91agi3
To: <sip:nathan at 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 at stage.illumy1.com parsing [default->global]
continue=true
Dialplan: sofia/internal/beth at stage.illumy1.com Absolute Condition [global]
Dialplan: sofia/internal/beth at stage.illumy1.com Action info()
Dialplan: sofia/internal/beth at stage.illumy1.com parsing
[default->Local_Users] continue=false
Dialplan: sofia/internal/beth at stage.illumy1.com Regex (PASS) [Local_Users]
destination_number(nathan) =~ /((?!^\d+$)^[a-zA-Z0-9_\-\.]+$)$/
break=on-false
Dialplan: sofia/internal/beth at stage.illumy1.com Action
set(continue_on_fail=false)
Dialplan: sofia/internal/beth at stage.illumy1.com Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/beth at stage.illumy1.com Action
set(bypass_media=true)
Dialplan: sofia/internal/beth at stage.illumy1.com Action
lua(endpoint_lookup.lua)
Dialplan: sofia/internal/beth at stage.illumy1.com Action set(call_timeout=20)
Dialplan: sofia/internal/beth at stage.illumy1.com Action
bridge(${dial_to_string})
Dialplan: sofia/internal/beth at stage.illumy1.com Action
set(bypass_media=false)
Dialplan: sofia/internal/beth at stage.illumy1.com Action answer()
Dialplan: sofia/internal/beth at stage.illumy1.com Action sleep(1000)
Dialplan: sofia/internal/beth at stage.illumy1.com Action
voicemail(${voicemail_string})
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:287
(sofia/internal/beth at 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 at 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 at 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 at stage.illumy1.com) State EXECUTE
2019-09-30 20:27:36.531844 [DEBUG] mod_sofia.c:209 sofia/internal/
beth at stage.illumy1.com SOFIA EXECUTE
2019-09-30 20:27:36.531844 [DEBUG] switch_core_state_machine.c:329
sofia/internal/beth at stage.illumy1.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/beth at 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 at 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 at 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 at stage.illumy1.com]
Caller-Caller-ID-Number: [beth]
Caller-Orig-Caller-ID-Name: [beth at 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 at 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 at 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 at 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 at 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 at stage.illumy1.com]
variable_sip_full_from: ["beth at stage.illumy1.com" <
sip:beth at stage.illumy1.com>;tag=36ov91agi3]
variable_sip_full_to: [<sip:nathan at 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 at stage.illumy1.com]
variable_sip_req_host: [stage.illumy1.com]
variable_sip_to_user: [nathan]
variable_sip_to_uri: [nathan at 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 at vg5qpm92h7dm.invalid]
variable_sip_contact_host: [vg5qpm92h7dm.invalid]
variable_rtp_use_codec_string: [OPUS,PCMU,VP8]
variable_sip_user_agent: [beth at stage.illumy1.com]
variable_sip_via_host: [vg5qpm92h7dm.invalid]
variable_sip_via_rport: [34010]
variable_max_forwards: [70]
variable_presence_id: [beth at 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 at 48000h@20i at 2c
,CORE_PCM_MODULE.PCMU at 8000h@20i at 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 at stage.illumy1.com
set(continue_on_fail=false)
2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
beth at stage.illumy1.com [continue_on_fail]=[false]
EXECUTE [depth=0] sofia/internal/beth at stage.illumy1.com
set(hangup_after_bridge=true)
2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
beth at stage.illumy1.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/beth at stage.illumy1.com
set(bypass_media=true)
2019-09-30 20:27:36.531844 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
beth at stage.illumy1.com [bypass_media]=[true]
EXECUTE [depth=0] sofia/internal/beth at 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 at 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 at 10.0.0.12:5080,${sofia_contact(
nathan at stage.illumy1.com)}')
2019-09-30 20:27:36.591836 [DEBUG] switch_cpp.cpp:1187 sofia/internal/
beth at stage.illumy1.com destroy/unlink session from object
EXECUTE [depth=0] sofia/internal/beth at stage.illumy1.com set(call_timeout=20)
2019-09-30 20:27:36.591836 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
beth at stage.illumy1.com [call_timeout]=[20]
EXECUTE [depth=0] sofia/internal/beth at stage.illumy1.com
bridge([sip_h_X-voicemailed=true,sip_h_X-local-call=true,sip_invite_domain=
stage.illumy1.com]sofia/external/nathan at 10.0.0.12:5080
,sofia/internal/sip:j7fd3415 at 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 at 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 at 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 at 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 at 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 at 10.0.0.12:5080) State INIT
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93 sofia/external/
nathan at 10.0.0.12:5080 SOFIA INIT
2019-09-30 20:27:36.591836 [NOTICE] switch_channel.c:1118 New Channel
sofia/internal/j7fd3415 at geutlen0uga7.invalid
[83e36ab7-8275-4a5e-9afd-f9356da57b06]
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:5096
(sofia/internal/j7fd3415 at geutlen0uga7.invalid) State Change CS_NEW ->
CS_INIT
2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618 sofia/external/
nathan at 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 at 3val7ifjblg6.invalid
[56c0cd2d-e19b-4c45-a278-81ed26d09636]
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:5096
(sofia/internal/r6ucrocm at 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 at 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 at stage.illumy1.com>;tag=UXNaNXZpme5SD
To: <sip:nathan at 10.0.0.12:5080>
Call-ID: 94fd528d-5e63-1238-2787-0251a831415e
CSeq: 10383836 INVITE
Contact: <sip:mod_sofia at 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 at 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 at 10.0.0.12:5080 Standard INIT
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48
(sofia/external/nathan at 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 at 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 at 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 at 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 at 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 at geutlen0uga7.invalid) State INIT
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93
sofia/internal/j7fd3415 at geutlen0uga7.invalid SOFIA INIT
2019-09-30 20:27:36.591836 [DEBUG] sofia.c:7289 Channel sofia/external/
nathan at 10.0.0.12:5080 entering state [terminated][503]
2019-09-30 20:27:36.591836 [NOTICE] sofia.c:8522 Hangup sofia/external/
nathan at 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 at 10.0.0.12:5080) State ROUTING
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154 sofia/external/
nathan at 10.0.0.12:5080 SOFIA ROUTING
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:644
(sofia/external/nathan at 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 at 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 at 50.246.121.173:39318;transport=wss Setting proxy route to
sofia/internal/j7fd3415 at geutlen0uga7.invalid
2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618
sofia/internal/j7fd3415 at 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 at 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 at 10.0.0.12:5080) State HANGUP
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:460 Channel sofia/external/
nathan at 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 at 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 at 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 at 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 at 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 at 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 at geutlen0uga7.invalid Standard INIT
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/j7fd3415 at 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 at geutlen0uga7.invalid) State INIT going to sleep
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585
(sofia/internal/j7fd3415 at 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 at geutlen0uga7.invalid) State ROUTING
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154
sofia/internal/j7fd3415 at geutlen0uga7.invalid SOFIA ROUTING
2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/j7fd3415 at 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 at geutlen0uga7.invalid) State ROUTING going to sleep
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585
(sofia/internal/j7fd3415 at 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 at geutlen0uga7.invalid) State CONSUME_MEDIA
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663
(sofia/internal/j7fd3415 at 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 at 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 at 3val7ifjblg6.invalid) State INIT
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:93
sofia/internal/r6ucrocm at 3val7ifjblg6.invalid SOFIA INIT
2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1587
sip:r6ucrocm at 50.246.121.173:34738;transport=wss Setting proxy route to
sofia/internal/r6ucrocm at 3val7ifjblg6.invalid
2019-09-30 20:27:36.591836 [DEBUG] sofia_glue.c:1618
sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid Standard INIT
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid) State INIT going to sleep
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585
(sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid) State ROUTING
2019-09-30 20:27:36.591836 [DEBUG] mod_sofia.c:154
sofia/internal/r6ucrocm at 3val7ifjblg6.invalid SOFIA ROUTING
2019-09-30 20:27:36.591836 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid) State ROUTING going to sleep
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:585
(sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid) State CONSUME_MEDIA
2019-09-30 20:27:36.591836 [DEBUG] switch_core_state_machine.c:663
(sofia/internal/r6ucrocm at 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 at geutlen0uga7.invalid entering state [calling][0]
send 3150 bytes to wss/[50.246.121.173]:34738 at 20:27:36.611364:
------------------------------------------------------------------------
INVITE sip:r6ucrocm at 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 at 50.246.121.173:34738>;transport=wss
Max-Forwards: 69
From: "Beth User" <sip:beth at 18.211.78.106>;tag=yHm5UmrgvjmeN

To: <sip:r6ucrocm at 3val7ifjblg6.invalid;transport=ws;received=
50.246.121.173:34738>
Call-ID: 94fe2e19-5e63-1238-2787-0251a831415e
CSeq: 10383836 INVITE
Contact: <sip:mod_sofia at 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 at 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 at 3val7ifjblg6.invalid entering state [calling][0]
2019-09-30 20:27:36.611834 [DEBUG] switch_core_state_machine.c:174
sofia/external/nathan at 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 at 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 at 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 at 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 at 18.211.78.106>;tag=yHm5UmrgvjmeN

To: <sip:r6ucrocm at 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 at 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 at 18.211.78.106>;tag=yHm5UmrgvjmeN
To: <sip:r6ucrocm at 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 at stage.illumy1.com
Contact: <sip:r6ucrocm at 3val7ifjblg6.invalid;transport=ws>
Content-Length: 0

2019-09-30 20:27:36.651842 [DEBUG] sofia.c:7289 Channel
sofia/internal/r6ucrocm at 3val7ifjblg6.invalid entering state
[proceeding][180]
2019-09-30 20:27:36.651842 [NOTICE] sofia.c:7400 Ring-Ready
sofia/internal/r6ucrocm at 3val7ifjblg6.invalid!
2019-09-30 20:27:36.651842 [NOTICE] mod_sofia.c:2505 Ring-Ready
sofia/internal/beth at 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 at stage.illumy1.com" <sip:beth at stage.illumy1.com>;tag=36ov91agi3
To: <sip:nathan at stage.illumy1.com>;tag=vZ1Kryp91078D
Call-ID: reo4dv21qm4aauclal7r

CSeq: 2 INVITE
Contact: <sip:nathan at 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 at 3val7ifjblg6.invalid) Callstate Change DOWN ->
RINGING
2019-09-30 20:27:36.651842 [DEBUG] sofia.c:7289 Channel sofia/internal/
beth at 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 at 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 at 18.211.78.106>;tag=yHm5UmrgvjmeN
To: <sip:r6ucrocm at 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 at stage.illumy1.com
Content-Length: 0

send 485 bytes to wss/[50.246.121.173]:34738 at 20:27:38.973840:
------------------------------------------------------------------------
ACK sip:r6ucrocm at 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 at 50.246.121.173:34738>;transport=wss
Max-Forwards: 69
From: "Beth User" <sip:beth at 18.211.78.106>;tag=yHm5UmrgvjmeN
To: <sip:r6ucrocm at 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 at 3val7ifjblg6.invalid entering state
[terminated][480]
2019-09-30 20:27:38.971902 [NOTICE] sofia.c:8522 Hangup
sofia/internal/r6ucrocm at 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 at 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 at 3val7ifjblg6.invalid) Callstate Change RINGING ->
HANGUP
2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:850
(sofia/internal/r6ucrocm at 3val7ifjblg6.invalid) State HANGUP
2019-09-30 20:27:38.971902 [DEBUG] mod_sofia.c:460 Channel
sofia/internal/r6ucrocm at 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 at 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 at 3val7ifjblg6.invalid) State HANGUP going to sleep
2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:620
(sofia/internal/r6ucrocm at 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 at 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 at 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 at 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 at 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 at 3val7ifjblg6.invalid) State REPORTING going to
sleep
2019-09-30 20:27:38.971902 [DEBUG] switch_core_state_machine.c:611
(sofia/internal/r6ucrocm at 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 at 3val7ifjblg6.invalid) Locked, Waiting on external
entities
-- 

><>
nathan stratton
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20190930/bdf5fc50/attachment-0001.html>