[Freeswitch-users] WSS Socket Disconnect

Wed Dec 6 02:01:02 UTC 2017

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 at 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 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
>
-- 

*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 at connectfirst.com / www.connectfirst.com <http://connectfirst.com/>

 [image:
https://docs.google.com/uc?export=download&id=0B5b6KnVfm9lJTlFrQzRVUjJ2ZVE&revid=0B5b6KnVfm9lJUXpUMTFEbGJvaktwN1p5ejM3YTFkdWVWNzBzPQ]

 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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20171206/78d87cb3/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image002.png
Type: image/png
Size: 4537 bytes
Desc: not available
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20171206/78d87cb3/attachment-0001.png>