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

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