Just wondering in anyone has any thoughts on the TCP disconnect. I have temporarily worked around the issue by putting nginx in the middle, but I now lose the IP of the registered user - so it’s not an ideal solution long term. Thanks in advance. Geoff On Sat, Dec 2, 2017 at 3:56 PM Geoff Mina <gmina@connectfirst.com> wrote:
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@c01-aorgc-reg6.somehost.biz SIP/2.0
Via: SIP/2.0/WSS hqj7ffmo2koa.invalid;branch=z9hG4bK1975235
Max-Forwards: 70
To: <sip:*97@c01-aorgc-reg6.somehost.biz>
From: "gmina" <sip:gmina@c01-aorgc-reg6.somehost.biz>;tag=efk4hqf1dc
Call-ID: vitn3acs5ss3dikrn14a
CSeq: 7808 INVITE
Contact: <sip:7jm943k7@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
-- *GEOFF MINA*Chief Executive Officer Connect First / Contact Center Solutions, Built Better. 3101 Iris Ave #200, Boulder, CO 80301 720.335.5924 <javascript:void(0);> gmina@connectfirst.com / www.connectfirst.com <http://connectfirst.com/> [image: https://docs.google.com/uc?export=download&id=0B5b6KnVfm9lJTlFrQzRVUjJ2ZVE&r...] This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager.
