[Freeswitch-users] WSS Socket Disconnect
Geoff Mina
gmina at connectfirst.com
Sat Dec 2 22:56:24 UTC 2017
I am having an issue where the WSS connection to Freeswitch is abruptly
disconnecting under certain scenarios. When trying to send an INVITE to
FreeSwitch, the socket disconnects. When accepting an INVITE from
FreeSwitch everything works fine.
I am running on CentOS 7 - 3.10.0-693.el7.x86_64. I installed Freeswitch
1.6.19 via yum. Here is what we are seeing from the browser side. Same
symptom in Chrome and FireFox:
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:34:52 GMT-0700 (MST) | sip.transaction.nist | Timer J
expired for non-INVITE server transaction z9hG4bKZmZS5KUSecFee
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
acquiring local media
sip-0.7.7.js:2900:3
onaddstream is deprecated! Use peerConnection.ontrack instead.
sip-0.7.7.js:11498
navigator.mozGetUserMedia has been replaced by
navigator.mediaDevices.getUserMedia
sip-0.7.7.js:10554:8
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
acquired local media streams
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
RTCIceGatheringState changed: gathering
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:0 1 UDP 2122252543 192.168.240.12 61028
typ host
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:2 1 UDP 2122187007 172.16.2.7 54757 typ
host
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:4 1 TCP 2105524479 192.168.240.12 9 typ
host tcptype active
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:5 1 TCP 2105458943 172.16.2.7 9 typ host
tcptype active
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:0 2 UDP 2122252542 192.168.240.12 61218
typ host
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:2 2 UDP 2122187006 172.16.2.7 52542 typ
host
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:4 2 TCP 2105524478 192.168.240.12 9 typ
host tcptype active
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:5 2 TCP 2105458942 172.16.2.7 9 typ host
tcptype active
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:3 1 UDP 1685987327 52.33.247.158 25669
typ srflx raddr 172.16.2.7 rport 54757
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:12 GMT-0700 (MST) | sip.invitecontext.mediahandler |
ICE candidate received: candidate:3 2 UDP 1685987326 52.33.247.158 16597
typ srflx raddr 172.16.2.7 rport 52542
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.invitecontext.mediahandler |
RTCIceChecking Timeout Triggered after 5000 milliseconds
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | sending WebSocket
message:
INVITE sip:*97 at c01-aorgc-reg6.somehost.biz SIP/2.0
Via: SIP/2.0/WSS hqj7ffmo2koa.invalid;branch=z9hG4bK1975235
Max-Forwards: 70
To: <sip:*97 at c01-aorgc-reg6.somehost.biz>
From: "gmina" <sip:gmina at c01-aorgc-reg6.somehost.biz>;tag=efk4hqf1dc
Call-ID: vitn3acs5ss3dikrn14a
CSeq: 7808 INVITE
Contact: <sip:7jm943k7 at hqj7ffmo2koa.invalid;transport=ws;ob>
Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER
Supported: outbound
User-Agent: SIP.js/0.7.7 BB\
Content-Type: application/sdp
Content-Length: 1646
v=0
o=mozilla...THIS_IS_SDPARTA-57.0 335274293698172607 0 IN IP4 0.0.0.0
s=-
t=0 0
a=sendrecv
a=fingerprint:sha-256
BE:35:AD:35:14:DB:CB:2B:D9:A3:D5:A7:EB:7D:08:E4:29:5E:7E:25:A6:16:9F:34:EC:37:0B:7A:C7:E0:9F:5B
a=group:BUNDLE sdparta_0
a=ice-options:trickle
a=msid-semantic:WMS *
m=audio 25669 UDP/TLS/RTP/SAVPF 109 9 0 8 101
c=IN IP4 52.33.247.158
a=candidate:0 1 UDP 2122252543 192.168.240.12 61028 typ host
a=candidate:2 1 UDP 2122187007 172.16.2.7 54757 typ host
a=candidate:4 1 TCP 2105524479 192.168.240.12 9 typ host tcptype active
a=candidate:5 1 TCP 2105458943 172.16.2.7 9 typ host tcptype active
a=candidate:0 2 UDP 2122252542 192.168.240.12 61218 typ host
a=candidate:2 2 UDP 2122187006 172.16.2.7 52542 typ host
a=candidate:4 2 TCP 2105524478 192.168.240.12 9 typ host tcptype active
a=candidate:5 2 TCP 2105458942 172.16.2.7 9 typ host tcptype active
a=candidate:3 1 UDP 1685987327 52.33.247.158 25669 typ srflx raddr
172.16.2.7 rport 54757
a=candidate:3 2 UDP 1685987326 52.33.247.158 16597 typ srflx raddr
172.16.2.7 rport 52542
a=sendrecv
a=extmap:1/sendonly urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=fmtp:109 maxplaybackrate=48000;stereo=1;useinbandfec=1
a=fmtp:101 0-15
a=ice-pwd:d45de180fdae3dc61f0e26238541045c
a=ice-ufrag:50681d44
a=mid:sdparta_0
a=msid:{23ed6231-4501-1944-8577-ab85c6c721cb}
{c98743c7-76d0-5c44-89a1-f702f7d8168d}
a=rtcp:16597 IN IP4 52.33.247.158
a=rtcp-mux
a=rtpmap:109 opus/48000/2
a=rtpmap:9 G722/8000/1
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=setup:actpass
a=ssrc:3742140108 cname:{76ae6d79-b818-1e40-a9bc-4734a437b47a}
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | WebSocket
disconnected (code: 1006)
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | WebSocket abrupt
disconnection
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.ua | connection state set to 1
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transaction.ict | transport
error occurred, deleting INVITE client transaction z9hG4bK1975235
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | Connection to
WebSocket wss://c01-aorgc-reg6.somehost.biz:8089/freeswitch severed,
attempting first reconnect
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | connecting to
WebSocket wss://c01-aorgc-reg6.somehost.biz:8089/freeswitch
sip-0.7.7.js:2900:3
Sat Dec 02 2017 15:35:17 GMT-0700 (MST) | sip.transport | WebSocket wss://
c01-aorgc-reg6.somehost.biz:8089/freeswitch connected
*And here is what we are seeing from the Freeswitch side.*
tport.c:2773 tport_wakeup() tport_wakeup(0x7f4e580fc4d0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f4e580fc4d0)
tport.c:2157 tport_shutdown0() tport_shutdown0(0x7f4e580fc4d0, 2)
tport.c:2090 tport_close() tport_close(0x7f4e580fc4d0): wss/
52.33.247.158:25656/sips
nua_registrar.c:200 registrar_tport_error() tport error 0: Success
tport.c:4222 tport_release() tport_release(0x7f4e580fc4d0): (nil) by
0x7f4e581361b0 with (nil)
tport.c:2263 tport_set_secondary_timer() tport(0x7f4e580fc4d0): set timer
at 0 ms because zap
*nua_stack.c:271 nua_stack_event() nua(0x7f4e581361b0): event i_media_error
500 Transport error detected*
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
tport.c:2263 tport_set_secondary_timer() tport(0x7f4e580fc4d0): set timer
at 0 ms because zap
tport_type_ws.c:521 tport_ws_deinit_secondary() 0x7f4e580fc4d0 destroy wss
transport 0x7f4e580fc6c0.
nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f4e581361b0): sent signal r_destroy
nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:569 nua_stack_signal() nua(0x7f4e581361b0): recv signal
r_destroy
nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f4e581361b0): removing
registrar usage
nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
soa.c:356 soa_destroy() soa_destroy(static::0x7f4e5803dea0) called
tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f4e58004f50): events IN
tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f4e58004f50):
new secondary tport 0x7f4e580fc4d0
tport.c:2292 tport_set_secondary_timer() tport(0x7f4e580fc4d0): set timer
at 4998 ms because keepalive
tport.c:2640 tport_accept() tport_accept(0x7f4e580fc4d0): new connection
from wss/52.33.247.158:54385/sips
tport.c:2773 tport_wakeup() tport_wakeup(0x7f4e580fc4d0): events IN
tport.c:2864 tport_recv_event() tport_recv_event(0x7f4e580fc4d0)
tport.c:2296 tport_set_secondary_timer() tport(0x7f4e580fc4d0): reset timer
tport.c:2773 tport_wakeup() tport_wakeup(0x7f4e580fc4d0): events IN
Any help in narrowing down the cause would be greatly appreciated. I am
thinking maybe it's a max frame size on the websocket or something... but I
couldn't find anything that would indicate there was a setting to tweak.
Thanks,
Geoff
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20171202/7cdb0b78/attachment-0001.html>
More information about the FreeSWITCH-users
mailing list