Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

***ERROR: function: "tsip_transport_layer_ws_cb()" #22

Open
GoogleCodeExporter opened this issue Aug 17, 2015 · 10 comments
Open

***ERROR: function: "tsip_transport_layer_ws_cb()" #22

GoogleCodeExporter opened this issue Aug 17, 2015 · 10 comments
Labels
auto-migrated Priority-Medium Type-Defect

Comments

@GoogleCodeExporter
Copy link 

What steps will reproduce the problem?

1. Got an error "***ERROR: function: "tsip_transport_layer_ws_cb()" in console 
then try to connect..

What is the expected output? What do you see instead?

# ./telepresence
*******************************************************************
Copyright (C) 2013 Doubango Telecom <http://www.doubango.org>
PRODUCT: telepresence - the open source TelePresence System
HOME PAGE: http://conf-call.org
CODE SOURCE: https://code.google.com/p/telepresence/
LICENCE: GPLv3 or commercial(contact us)
VERSION: 2.1.0
'quit' to quit the application.
*******************************************************************

SSL is enabled :)
DTLS supported: yes
DTLS-SRTP supported: yes
*INFO: [TELEPRESENCE] [CFG] debug-audio-loopback = no
*INFO: [TELEPRESENCE] [CFG] accept-sip-reg = no
*INFO: [TELEPRESENCE] [CFG] transport = udp;*;20060;*
*INFO: [TELEPRESENCE] [CFG] transport = udp://*:20060@*
*INFO: [TELEPRESENCE] [CFG] transport = ws;*;20060;4
*INFO: [TELEPRESENCE] [CFG] transport = ws://*:20060@4
*INFO: [TELEPRESENCE] [CFG] transport = http;*;20065
*INFO: [TELEPRESENCE] [CFG] transport = https;*;20066
*INFO: [TELEPRESENCE] [CFG] rtp-symmetric-enabled = no
*INFO: [TELEPRESENCE] [CFG] ice-enabled = no
*INFO: [TELEPRESENCE] [CFG] icestun-enabled = no
*INFO: [TELEPRESENCE] [CFG] stun-server = 
stun.l.google.com;19302;[email protected];stun-password
*INFO: [TELEPRESENCE] [CFG] stun-server = stun.l.google.com;19302;-;-
*INFO: [TELEPRESENCE] [CFG] rtcp-mux-enabled = yes
*INFO: [TELEPRESENCE] [CFG] rtp-buffersize = 65535
*INFO: [TELEPRESENCE] [CFG] avpf-tail-length = 200;500
*INFO: [TELEPRESENCE] [CFG] codecs = g729;vp8
*INFO: 'g729' codec enabled but not supported
*INFO: 'vp8' codec enabled but not supported
*INFO: [TELEPRESENCE] [CFG] codec-opus-maxrates = 48000;48000
*INFO: [TELEPRESENCE] [CFG] congestion-ctrl-enabled = yes
*INFO: [TELEPRESENCE] [CFG] video-max-upload-bandwidth = 1890
*INFO: [TELEPRESENCE] [CFG] video-max-download-bandwidth = 1890
*INFO: [TELEPRESENCE] [CFG] video-motion-rank = 2
*INFO: [TELEPRESENCE] [CFG] video-fps = 15
*INFO: [TELEPRESENCE] [CFG] video-jb-enabled = yes
*INFO: [TELEPRESENCE] [CFG] video-zeroartifacts-enabled = yes
*INFO: [TELEPRESENCE] [CFG] video-mixed-size = vga
*INFO: [TELEPRESENCE] [CFG] video-speaker-par = 0:0
*INFO: [TELEPRESENCE] [CFG] video-listener-par = 1:1
*INFO: [TELEPRESENCE] [CFG] audio-channels = 1
*INFO: [TELEPRESENCE] [CFG] audio-bits-per-sample = 16
*INFO: [TELEPRESENCE] [CFG] audio-sample-rate = 8000
*INFO: [TELEPRESENCE] [CFG] audio-ptime = 20
*INFO: [TELEPRESENCE] [CFG] audio-volume = 1.0f
*INFO: [TELEPRESENCE] [CFG] audio-dim = 2d
*INFO: [TELEPRESENCE] [CFG] audio-max-latency = 200
*INFO: [TELEPRESENCE] [CFG] record = no
*INFO: [TELEPRESENCE] [CFG] record-file-ext = avi
*INFO: [TELEPRESENCE] [CFG] overlay-fonts-folder-path = 
./fonts/truetype/freefont
*INFO: [TELEPRESENCE] [CFG] overlay-copyright-text = Doubango Telecom
*INFO: [TELEPRESENCE] [CFG] overlay-copyright-fontsize = 12
*INFO: [TELEPRESENCE] [CFG] overlay-copyright-fontfile = FreeSerif.ttf
*INFO: [TELEPRESENCE] [CFG] overlay-speaker-name-enabled = yes
*INFO: [TELEPRESENCE] [CFG] overlay-speaker-name-fontsize = 16
*INFO: [TELEPRESENCE] [CFG] overlay-speaker-name-fontfile = FreeMonoBold.ttf
*INFO: [TELEPRESENCE] [CFG] overlay-speaker-jobtitle-enabled = yes
*INFO: [TELEPRESENCE] [CFG] overlay-watermark-image-path = 
./images/logo35x34.jpg
*INFO: [TELEPRESENCE] [CFG] ssl-private-key = /tmp/teleconf-xxx-key.pem
*INFO: [TELEPRESENCE] [CFG] ssl-public-key = /tmp/teleconf-xxx-key.pem
*INFO: [TELEPRESENCE] [CFG] ssl-ca = /tmp/teleconf-xxx-key.pem
*INFO: [TELEPRESENCE] [CFG] ssl-mutual-auth = no
*INFO: [TELEPRESENCE] [CFG] srtp-mode = optional
*INFO: [TELEPRESENCE] [CFG] srtp-type = sdes;dtls
*INFO: [TELEPRESENCE] [CFG] presentation-sharing-enabled = no
*INFO: [TELEPRESENCE] [CFG] presentation-sharing-process-local-port = 2083
*INFO: [TELEPRESENCE] [CFG] presentation-sharing-base-folder = ./presentations
*INFO: [TELEPRESENCE] [CFG] presentation-sharing-app = soffice
*INFO: [TELEPRESENCE] [CFG] Bridge with id ='10060' added
*INFO: [TELEPRESENCE] [CFG] Bridge with id ='10061' added
*INFO: [TELEPRESENCE] Presentation sharing not enabled
*INFO: Stack running in SERVER mode
*INFO: tsk_timer_manager_start
*INFO: Timer manager run()::enter
*INFO: TIMER MANAGER -- START
*INFO: SIP STACK::run -- START
*INFO: tnet_transport_prepare()
*INFO: pipeR fd=5
*INFO: Socket added[SIP transport]: fd=5, tail.count=1
*INFO: master fd=3
*INFO: Socket added[SIP transport]: fd=3, tail.count=2
*INFO: tnet_transport_prepare()
*INFO: Transport::run() - enter
*INFO: pipeR fd=7
*INFO: Socket added[SIP transport]: fd=7, tail.count=1
*INFO: master fd=4
*INFO: Socket added[SIP transport]: fd=4, tail.count=2
*INFO: Starting [SIP transport] server with IP {192.168.99.99} on port {20060} 
using fd {3} with type {2}...
*INFO: Transport::run() - enter
*INFO: SIP STACK -- START
*INFO: Starting [SIP transport] server with IP {192.168.99.99} on port {20060} 
using fd {4} with type {64}...
*INFO: ioctlt(4), len=0 returned zero or failed
*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- FD_ACCEPT(fd=9)
*INFO: Socket added[SIP transport]: fd=9, tail.count=3
*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- TNET_POLLOUT
*INFO: WebSocket Peer accepted/connected with fd = 9
*INFO: #1 peers in the 'SIP transport' transport
*INFO: WebSocket handshake message: GET / HTTP/1.1
Host: 192.168.0.21:20060
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:26.0) Gecko/20100101 
Firefox/26.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: ru-RU,ru;q=0.8,en-US;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Sec-WebSocket-Version: 13
Origin: http://xxx.yyy.zzz.com
Sec-WebSocket-Protocol: sip
Sec-WebSocket-Key: wmkDEUSqxVD7QuQSh+saXw==
Connection: keep-alive, Upgrade
Pragma: no-cache
Cache-Control: no-cache
Upgrade: websocket


*INFO: WebSocket Peer accepted/connected with fd = 9
*INFO: *** Stream Peer destroyed ***
*INFO: #0 peers in the 'SIP transport' transport
*INFO: #1 peers in the 'SIP transport' transport
***ERROR: function: "tsip_transport_layer_ws_cb()"
file: "src/transports/tsip_transport_layer.c"
line: "397"
MSG: WS handshaking not done yet
*INFO: Removing socket 9
*INFO: Socket to remove: fd=9, index=2, tail.count=3
*INFO: RemoveSocket(fd=9) has been requested but we are poll()ing the socket. 
ShutdownSocket(fd) called on the socket and we deferred the request.
*INFO: ShutdownSocket(fd=9)
*INFO: WebSocket Peer closed with fd = 9
*INFO: #0 peers in the 'SIP transport' transport
*INFO: PipeR event = 1
*INFO: *** Stream Peer destroyed ***
*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- TNET_POLLHUP(9)
*INFO: Removing socket 9
*INFO: Socket to remove: fd=9, index=2, tail.count=3
*INFO: CloseSocket(9)
*INFO: PipeR event = 1
*INFO: WebSocket Peer closed with fd = 9
*INFO: WebSocket Peer closed with fd = 9


What version of the product are you using? On what operating system?

Centos 6.5 64-bit, Mozilla Firefox 26.0

Please provide any additional information below.

How can i figure this out?

Original issue reported on code.google.com by [email protected] on 19 Dec 2013 at 10:03
@GoogleCodeExporter
Copy link
Author 

Getting the same issue on Centos 6.5 32bit

*INFO: WebSocket Peer accepted/connected with fd = 15
*INFO: *** Stream Peer destroyed ***
*INFO: #0 peers in the 'SIP transport' transport
*INFO: #1 peers in the 'SIP transport' transport
***ERROR: function: "tsip_transport_layer_ws_cb()"
file: "src/transports/tsip_transport_layer.c"
line: "397"
MSG: WS handshaking not done yet
*INFO: Removing socket 15
*INFO: Socket to remove: fd=15, index=2, tail.count=3
*INFO: RemoveSocket(fd=15) has been requested but we are poll()ing the socket. 
ShutdownSocket(fd) called on the socket and we deferred the request.
*INFO: ShutdownSocket(fd=15)
*INFO: WebSocket Peer closed with fd = 15
*INFO: #0 peers in the 'SIP transport' transport
*INFO: *** Stream Peer destroyed ***
*INFO: PipeR event = 1
*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- TNET_POLLHUP(15)
*INFO: Removing socket 15
*INFO: Socket to remove: fd=15, index=2, tail.count=3
*INFO: CloseSocket(15)
*INFO: PipeR event = 1
*INFO: WebSocket Peer closed with fd = 15
*INFO: WebSocket Peer closed with fd = 15

Original comment by [email protected] on 1 Jan 2014 at 4:36

@GoogleCodeExporter
Copy link
Author 

Same problem on Ubuntu 12.04 64bit, Firefox 26 and doubango version 2.6.0. With 
Chrome 31 all works fine.

Original comment by pburlov on 14 Jan 2014 at 1:01

Attachments:

@GoogleCodeExporter
Copy link
Author 

It happens sometimes also on Chrome :(

Original comment by [email protected] on 25 Mar 2014 at 10:59

@GoogleCodeExporter
Copy link
Author 

After searching and trying I have found that it has something to do with ssl 
certicates

Original comment by [email protected] on 29 Mar 2014 at 12:07

@GoogleCodeExporter
Copy link
Author 

So now what? 
Same problem here!!

Original comment by [email protected] on 26 Jun 2014 at 3:03

@GoogleCodeExporter
Copy link
Author 

Nothing?

Original comment by [email protected] on 7 Jul 2014 at 1:07

@GoogleCodeExporter
Copy link
Author 

Can you explain the reasoning behind why you believe it has something to do 
with SSL certificates?

Original comment by [email protected] on 9 Jul 2014 at 8:38

@GoogleCodeExporter
Copy link
Author 

So, I'm tracking it to something strange happening with the peer->ws structure 
for the currently connected peer.

I put a LOG print inside  tsip_transport_layer_ws_cb(const 
tnet_transport_event_t* e) to print 
the current status of the peer->ws.handshaking_done variable.

It seems like the socket connects, it detects the GET, everything checks out 
and handshaking_done is set, and then for the next packet that comes in, 
suddenly handshaking_done is '0' again. I print the address of the peer to 
prove it is the same structure both times.

Either it's some kind of race condition, or some condition happens in the 
middle that resets the structure:

This is the part of interest:
"*INFO: SETTING HANDSHAKING DONE on dc007830 0
*INFO: SET HANDSHAKING DONE on dc007830 1
*INFO: WebSocket Peer accepted/connected with fd = 18
*INFO: *** Stream Peer destroyed ***
*INFO: #0 peers in the 'SIP transport' transport
*INFO: #1 peers in the 'SIP transport' transport
*INFO: FIRST BYTES OF WEBSOCKET PACKET: � � � 
*INFO: CHECKING HANDSHAKING DONE on dc007830 0
"

*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- FD_ACCEPT(fd=18)
*INFO: Socket added[SIP transport]: fd=18, tail.count=3
*INFO: NETWORK EVENT FOR SERVER [SIP transport] -- TNET_POLLOUT
*INFO: WebSocket Peer accepted/connected with fd = 18
*INFO: #1 peers in the 'SIP transport' transport
*INFO: FIRST BYTES OF WEBSOCKET PACKET: G E T  
*INFO: CHECKING HANDSHAKING DONE on dc007830 0
*INFO: WebSocket handshake message: GET / HTTP/1.1
Upgrade: websocket
Connection: Upgrade
Host: 204.236.130.239:20060
Origin: http://192.168.1.72:3000
Sec-WebSocket-Protocol: sip
Pragma: no-cache
Cache-Control: no-cache
Sec-WebSocket-Key: GZ08ej3U8xLrnlkTt368/Q==
Sec-WebSocket-Version: 13
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits, 
x-webkit-deflate-frame
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 
(KHTML, like Gecko) Chrome/35.0.1916.153 Safari/537.36


*INFO: IS WEBSOCKET PROTOCOL
*INFO: FOUND SIP
*INFO: SENDING SWITCH PROTOCOL RESPONSE
*INFO: SENDING RESPONSE
*INFO: SETTING HANDSHAKING DONE on dc007830 0
*INFO: SET HANDSHAKING DONE on dc007830 1
*INFO: WebSocket Peer accepted/connected with fd = 18
*INFO: *** Stream Peer destroyed ***
*INFO: #0 peers in the 'SIP transport' transport
*INFO: #1 peers in the 'SIP transport' transport
*INFO: FIRST BYTES OF WEBSOCKET PACKET: � � � 
*INFO: CHECKING HANDSHAKING DONE on dc007830 0
***ERROR: function: "tsip_transport_layer_ws_cb()" 
file: "src/transports/tsip_transport_layer.c" 
line: "410" 
MSG: WS handshaking not done yet

Original comment by [email protected] on 9 Jul 2014 at 9:44

@GoogleCodeExporter
Copy link
Author 

So, I noticed the non-blocking versus blocking state machine handles the 
'accepted/connected' condition differently.

Maybe this is an error where a fix in one didn't quite make it to the other?

I've modified tsip_transport_layer.c in doubango with the following change:
Line 367:
{{{
                case event_accepted:
                case event_connected:
                        {
                                tsip_transport_stream_peer_t* peer;
                                // find peer
                                if((peer = tsip_transport_find_stream_peer_by_local_fd(transport, e->local_fd))){
                                        // If peer already exists.. do nothing :0
                                        return  0;
                                }
                                else {
                                        TSK_DEBUG_INFO("WebSocket Peer accepted/connected with fd = %d", e->local_fd);
                                        return tsip_transport_add_stream_peer(transport, e->local_fd, transport->type, tsk_true);
                                }
                        }
}}}

And now I don't get the intermittent connection failures because the 
handshaking_done flag now stays consistent to the overall state of the 
websocket.

If you look at line 175, it seems to perform some similar functionality where 
it searches for the peer, and if it finds it it doesn't create a new stream... 
but instead strangely frees the memory behind the peer.

Original comment by [email protected] on 9 Jul 2014 at 10:37

@GoogleCodeExporter
Copy link
Author 

is there some reason the above changes have not been accepted upstream and is 
there any other workaround for this issue ?

Original comment by [email protected] on 4 Aug 2015 at 3:51

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
auto-migrated Priority-Medium Type-Defect
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@GoogleCodeExporter