[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