Pb with DTLS ?
1,255 views
Skip to first unread message
William MANCON
Jan 14, 2015, 5:07:43 AM1/14/15
to meetech...@googlegroups.com
Hi Lorenzo,
I installed recently janus on a new serveur and i can't get it to work..
Could you help me to understand the pb ?
Here is my log : http://pastebin.com/ERALNdva
Everything seems to be ok with signaling, the negociation (offer/answer..) until browser or janus need to send audio or video data.
There is NO network filtering on server side (iptables...).
On the client side, with the echo test plugin, (or mcu..) the audio or video data is never sent. After negociation, the client try to exchange the DTLS certificate but no success :
614 127.902451000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client Hello
627 129.150940000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication
673 154.168432000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication
719 187.843888000 10.42.0.77 92.202.78.142 DTLSv1.0 153 Server Hello
720 187.844185000 10.42.0.77 92.202.78.142 DTLSv1.0 507 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]
721 187.845172000 10.42.0.77 92.202.78.142 DTLSv1.0 99 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]
722 187.845268000 10.42.0.77 92.202.78.142 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
723 187.892663000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client Hello
754 204.590344000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication
798 229.152028000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication
849 247.846145000 10.42.0.77 92.202.78.142 DTLSv1.0 153 Server Hello
850 247.846484000 10.42.0.77 92.202.78.142 DTLSv1.0 507 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]
851 247.846565000 10.42.0.77 92.202.78.142 DTLSv1.0 99 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]
852 247.846638000 10.42.0.77 92.202.78.142 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
853 247.909974000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client Hello
That is strange, the certificate (certs by default) is the same on the test machine, and everything is ok. On the new server even if there is a network issue, i can't understand why it is causing probleme with the DTLS certificate exchange.
With the video MCU, when i close the session, nothing strange appears, ressources a freed etc. Janus always record audio and video empty files (15 o).
Do you have an idea ?
Thank you ;)
William MANCON
Jan 14, 2015, 6:53:31 AM1/14/15
to meetech...@googlegroups.com
The server is on a open network, with a public ip address, accessible, and with a large bandw capacity.
The client is behind a NAT, with a poor quality connection, but it works great with opentok and co ....
Lorenzo Miniero
Jan 14, 2015, 9:51:55 AM1/14/15
to meetech...@googlegroups.com
Is this Firefox stable? (appears so, from the log). If so, there's an issue we're trying to solve there that may be libnice related. Let me know if things work fine with Chrome and Firefox Nightly instead.
L.
William MANCON
Jan 14, 2015, 11:04:15 AM1/14/15
to meetech...@googlegroups.com
I'll test with Nightly.
Do you need a log for each browser ?
With the same client(OS ..) same browser, same build (janus) it works fine on the test server (but the test server is in local network....).
William MANCON
Jan 14, 2015, 11:05:53 AM1/14/15
to meetech...@googlegroups.com
Firefox version : 28.0 (Ubuntu 14.04).
Lorenzo Miniero
Jan 14, 2015, 11:10:58 AM1/14/15
to meetech...@googlegroups.com
A test with Chrome might help. Nightly unlike Stable does bundling, which makes things easier for libnice.
L.
William MANCON
Jan 14, 2015, 12:46:36 PM1/14/15
to meetech...@googlegroups.com
Ok, i'm testing it !
libnice version : libnice-dev_0.1.4-1_amd64.deb
William MANCON
Jan 14, 2015, 2:31:26 PM1/14/15
to meetech...@googlegroups.com
Same results with chrome 40.0.2214.69.
Do i need to try with a different version of libnice ?
It's ok too with your demo serveur (plugin echo test), what if i build the same system/lib than the local test server ?
I'm not sure to understand this part of the log :
STUN error: Incomplete message: 111 of 65300 bytes!
[1540245456] Looks like DTLS!
[1540245456] DTLS check pending: 0
Written 111 of those bytes on the read BIO...
[1540245456] DTLS check pending: 0
... and read -1 of them from SSL... [1540245456] DTLS check pending: 0
65300 bytes, what kind of message could take so much data ? (it's the google stun server, no turn)
Lorenzo Miniero
Jan 14, 2015, 3:06:46 PM1/14/15
to meetech...@googlegroups.com
Probably an error parsing a STUN connectivity check or response.
What about the DTLS related debug messages for a session?
L.
William MANCON
Jan 14, 2015, 5:57:47 PM1/14/15
to meetech...@googlegroups.com
I'm not sure to understand, you want a dump of the janus log, filtered with only DTLS ?
Here what happend when i'm testing on the local server :
2650215640] DTLS check pending: 197
[2650215640] >> Going to send DTLS data: 197 bytes
[2650215640] >> >> Read 197 bytes from the write_BIO...
(process:14603): libnice-DEBUG: Agent 0x7fc02800b6d0 : s1:1: sending 197 bytes to [10.42.0.77]:34211
[2650215640] >> >> ... and sent 197 of those bytes on the socket
[2650215640] DTLSv1_get_timeout: 999
(process:14603): libnice-DEBUG: Agent 0x7fc02800b6d0 : Packet received on local socket 20 from [10.42.0.77]:34211 (835 octets).
STUN error: Incomplete message: 835 of 65300 bytes!
Looks like DTLS!
[2650215640] DTLS check pending: 0
Written 835 of those bytes on the read BIO...
[2650215640] DTLS check pending: 0
... and read -1 of them from SSL...
[2650215640] DTLS check pending: 1105
[2650215640] >> Going to send DTLS data: 1105 bytes
[2650215640] >> >> Read 1105 bytes from the write_BIO...
(process:14603): libnice-DEBUG: Agent 0x7fc02800b6d0 : s1:1: sending 1105 bytes to [10.42.0.77]:34211
[2650215640] >> >> ... and sent 1105 of those bytes on the socket
Initialization not finished yet...
(process:14603): libnice-DEBUG: Agent 0x7fc02800b6d0 : Packet received on local socket 20 from [10.42.0.77]:34211 (91 octets).
STUN error: Incomplete message: 91 of 65300 bytes!
Looks like DTLS!
[2650215640] DTLS check pending: 0
Written 91 of those bytes on the read BIO...
[2650215640] DTLS check pending: 0
... and read -1 of them from SSL...
[2650215640] DTLS check pending: 0
[2650215640] DTLS established, yay!
With the same client, on the "new" server :
DTLSv1_get_timeout: 0 [2462730371] DTLS timeout on component 1 of stream 1, retransmitting [2462730371] DTLS check pending: 197 [2462730371] >> Going to send DTLS data: 197 bytes [2462730371] >> >> Read 197 bytes from the write_BIO... (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 : s1:1: sending 197 bytes to [78.250.25.170]:60030 [2462730371] >> >> ... and sent 197 of those bytes on the socket [2462730371] DTLSv1_get_timeout: 1899 [2462730371] DTLSv1_get_timeout: 1798 (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 :STUN transaction retransmitted (timeout 2385ms). [2462730371] DTLSv1_get_timeout: 1698 [2462730371] DTLSv1_get_timeout: 1597 (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 : timer tick #101: 0 frozen, 1 in-progress, 0 waiting, 1 succeeded, 0 discovered, 1 nominated, 0 waiting-for-nom. (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 : Packet received on local socket 24 from [78.250.25.170]:60030 (835 octets). STUN error: Incomplete message: 835 of 65300 bytes! [2462730371] Looks like DTLS! [2462730371] DTLS check pending: 0 Written 835 of those bytes on the read BIO... [2462730371] DTLS check pending: 0 ... and read -1 of them from SSL... [2462730371] DTLS check pending: 0 Initialization not finished yet... (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 : Packet received on local socket 24 from [78.250.25.170]:60030 (104 octets). (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0: inbound STUN packet for 1/1 (stream/component) from [78.250.25.170]:60030 (104 octets) : STUN demux: OK! Comparing username '0x516252393a4b56337658782f4d5944463132663578' (21) with '0x51625239' (4) : 0 Found valid username, returning password: 'iBDdyXs0Mcw+hhUW2Cf2Mq' Message HMAC-SHA1 fingerprint: key : 0x69424464795873304d63772b68685557324366324d71 expected: 0x6c8e3917cd04ec9dbcb6f43753bef7aa279aac0c received: 0x6c8e3917cd04ec9dbcb6f43753bef7aa279aac0c STUN auth: OK! STUN unknown: 0 mandatory attribute(s)! STUN Reply (buffer size = 1300)... STUN Role not specified by peer! Message HMAC-SHA1 message integrity: key : 0x69424464795873304d63772b68685557324366324d71 sent : 0x5a1e79b9fb5b6e77e795b2deced06296e47f0e7b Message HMAC-SHA1 fingerprint: 0x33d828b0 All done (response size: 92) [2462730371] DTLSv1_get_timeout: 0 [2462730371] DTLS timeout on component 1 of stream 1, retransmitting [2462730371] DTLS check pending: 197 [2462730371] >> Going to send DTLS data: 197 bytes [2462730371] >> >> Read 197 bytes from the write_BIO... (process:709): libnice-DEBUG: Agent 0x7f06b000b6d0 : s1:1: sending 197 bytes to [78.250.25.170]:60030 [2462730371] >> >> ... and sent 197 of those bytes on the socket
and it reapeat those sequences, sometimes the first 197 byte, sometimes the 197 bytes long + 2nd 835 bytes long, but never reach the
thrid packet (just before DTLS established, yay!) in the first exemple (the good one).
Lorenzo Miniero
Jan 14, 2015, 6:05:56 PM1/14/15
to William MANCON, meetech...@googlegroups.com
The retransmissions may mean that the DTLS messages Janus is originating either don't reach the client for some reason (Wireshark is your friend there) or it's not leaving the server at all, although libnice seems to indicate the bytes have been sent. You'll have to look at what's actually being sent and received on the two ends to check that.
L.
--
You received this message because you are subscribed to the Google Groups "meetecho-janus" group.
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janu...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
William MANCON
Jan 14, 2015, 6:24:30 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
On the client side , with the new server
261 14.110595000 92.201.18.212 10.42.0.77 DTLSv1.0 239 Client Hello
262 14.110833000 10.42.0.77 92.201.18.212 DTLSv1.0 929 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
263 14.432091000 92.201.18.212 10.42.0.77 DTLSv1.0 239 Client Hello
264 14.432333000 10.42.0.77 92.201.18.212 DTLSv1.0 929 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
265 14.478330000 92.201.18.212 10.42.0.77 DTLSv1.0 239 Client Hello
266 14.478585000 10.42.0.77 92.201.18.212 DTLSv1.0 929 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
268 16.112321000 10.42.0.77 92.201.18.212 DTLSv1.0 929 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
269 16.129442000 92.201.18.212 10.42.0.77 DTLSv1.0 239 Client Hello
273 16.433052000 10.42.0.77 92.201.18.212 DTLSv1.0 929 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
With the local server (no pb here),
135 9.244476000 10.56.128.135 10.42.0.77 DTLSv1.0 239 Client Hello
136 9.254475000 10.42.0.77 10.42.0.1 DTLSv1.0 877 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
137 9.257983000 10.56.128.135 10.42.0.77 DTLSv1.0 1147 Certificate, Client Key Exchange, Certificate Verify, Change Cipher Spec, Encrypted Handshake Message
138 9.277939000 10.42.0.77 10.42.0.1 DTLSv1.0 133 Change Cipher Spec, Encrypted Handshake Message
the result on your demo server is quite the same. I'm trying to capture the traffic on server side.
Lorenzo Miniero
Jan 14, 2015, 6:32:47 PM1/14/15
to William MANCON, meetech...@googlegroups.com
But is this from the same session? I see different sizes there.
L.
L.
William MANCON
Jan 14, 2015, 6:48:12 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
Its from the same session but maybe at a different time. The pb loop until the browser (?) stop.
On server side, for a different session, but always the same scenario/client ..
William MANCON
Jan 14, 2015, 6:49:31 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
The size reported by wireshark are never the same than in the log. I dont know why.
William MANCON
Jan 14, 2015, 7:01:05 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
I do not see networks pbs. it seems that data leave the server and the client.
Sometimes there is data retransmition, as in the previous log but, most of the time packets are well sent/received.
William MANCON
Jan 14, 2015, 7:12:18 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
I tried on a different network (of good quality, wired) today for the client, it was the same result. I don't think the retransmition of the certificate, or the reassembly error is due to the network.
As far as I know, there is no (hard) firewall on the server...
On the client side I can connect to your demo server and use the echo test demo without pb.
William MANCON
Jan 14, 2015, 7:58:09 PM1/14/15
to meetech...@googlegroups.com, wma...@gmail.com
William MANCON
Jan 15, 2015, 9:25:13 AM1/15/15
to meetech...@googlegroups.com, wma...@gmail.com
Today i tried on another network for the client, wired.
Here is the first 3 packet of the handshake, when trying with your demo server.
With the same browser/network, i tried on my new server (92.202.112.202) and dumped data traffic both on client/server side.
The begining of the handshake :
75 10.858288 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
76 10.916547 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
82 11.121708 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
87 11.122715 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
89 11.173239 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
90 11.181635 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
96 11.865395 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
97 11.909176 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
101 12.129202 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
102 12.130459 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
103 12.174007 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
104 12.182653 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
115 13.880321 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
116 13.909973 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
121 14.144043 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
122 14.145310 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
123 14.174860 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
124 14.182736 82.238.246.126 92.202.112.202 DTLSv1.0 930 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
152 17.903984 82.238.246.126 92.202.112.202 DTLSv1.0 153 Server Hello
153 17.904250 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello
154 17.908685 82.238.246.126 92.202.112.202 DTLSv1.0 507 Certificate (Fragment)
155 17.909877 82.238.246.126 92.202.112.202 DTLSv1.0 99 Certificate (Reassembled)
156 17.912338 82.238.246.126 92.202.112.202 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
I do not understand why the begining of the handshake repeat. The client certificate is different. The client is the same, but it send another certificate ?
When client browser communicate with your demo server, the certificate is 416 byte long and with my new server, its 469 byte long ...
It's a litle bit strange :
154 17.908685 82.238.246.126 92.202.112.202 DTLSv1.0 507 Certificate (Fragment)
155 17.909877 82.238.246.126 92.202.112.202 DTLSv1.0 99 Certificate (Reassembled)
No network issue here ? but it does not follow the same logic as with your demo server (or the local here, the good one)
This line :
141 13.359391000 143.225.229.138 192.168.0.32 DTLSv1.0 1147 Certificate, Client Key Exchange, Certificate Verify, Change Cipher Spec, Encrypted Handshake Message
We never reach this step on my new server. But, with your server, the first two packet NEVER repeat.
Is the repetition of those 2 packet is responsible of the error ? and why, do you have any idea ?
On the very first example in this post, we see the server send 92.202.112.202 82.238.246.126 DTLSv1.0 239 Client Hello to the client, instead of Certificate, Client Key Exchange, Certificate Verify, Change Cipher Spec, Encrypted Handshake Message. is it because something is not correct in the client certificate (469 byte long) ?
I dont know how to investigate deeper... If you have any idea here, ;)
Thanks for yours replies.
WM.
William MANCON
Jan 15, 2015, 9:43:55 AM1/15/15
to meetech...@googlegroups.com, wma...@gmail.com
Finaly, another try with chrome 40, on the "new server"
No. Time Source Destination Protocol Length Info
144 11.521547000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello
149 11.757865000 192.168.0.32 92.202.112.202 DTLSv1.0 877 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
157 12.526796000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello
158 12.527638000 192.168.0.32 92.202.112.202 DTLSv1.0 877 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
167 14.527538000 192.168.0.32 92.202.112.202 DTLSv1.0 877 Server Hello, Certificate, Server Key Exchange, Certificate Request, Server Hello Done
168 14.536644000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello
199 18.528557000 192.168.0.32 92.202.112.202 DTLSv1.0 153 Server Hello
200 18.528644000 192.168.0.32 92.202.112.202 DTLSv1.0 486 Certificate
201 18.528682000 192.168.0.32 92.202.112.202 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
202 18.557109000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello
263 26.529507000 192.168.0.32 92.202.112.202 DTLSv1.0 153 Server Hello
264 26.529588000 192.168.0.32 92.202.112.202 DTLSv1.0 486 Certificate
265 26.529895000 192.168.0.32 92.202.112.202 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
266 26.565826000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello
Here the expanded version : http://pastebin.com/UWDDEPgi
The handshake is strange, same pb, but no reassambly error, or "fragment". Just the Server hello, certificate, server key exchange etc are in 3 packet
263 26.529507000 192.168.0.32 92.202.112.202 DTLSv1.0 153 Server Hello
264 26.529588000 192.168.0.32 92.202.112.202 DTLSv1.0 486 Certificate
265 26.529895000 192.168.0.32 92.202.112.202 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done
Size are different. I cannot see network issue, and the server send 266 26.565826000 92.202.112.202 192.168.0.32 DTLSv1.0 239 Client Hello.
Very strange for me. If someone could give an idea ?
Thanks.
Lorenzo Miniero
Jan 15, 2015, 9:58:56 AM1/15/15
to meetech...@googlegroups.com, wma...@gmail.com
No time to look into this right now, sorry. I'll get back to this next week.
L.
William MANCON
Jan 15, 2015, 10:23:31 AM1/15/15
to meetech...@googlegroups.com, wma...@gmail.com
Ok, thank you for your answer, i'll put here new investigations.
William MANCON
Jan 16, 2015, 6:58:47 AM1/16/15
to meetech...@googlegroups.com, wma...@gmail.com
I made some data integrity checks.
For the first packet of (197 bytes from server to client) :
16 FE FF 00 00 00 00 00 00 00 00 00 B8 01 00 00 AC 00 00 00 00 00 00 00 AC FE FF EE F1 D5 B9 9B 95 B0 94 A1 D4 18 0E 9F E7 BA 54 69 CB 5A F7 EA F8 DE 14
24 B1 0E E0 B5 18 70 A5 00 00 00 70 C0 14 C0 0A 00 39 00 38 00 88 00 87 C0 19 00 3A 00 89 C0 0F C0 05 00 35 00 84 C0 12 C0 08 00 16 00 13 C0 17 00 1B
C0 0D C0 03 00 0A C0 13 C0 09 00 33 00 32 00 9A 00 99 00 45 00 44 C0 18 00 34 00 9B 00 46 C0 0E C0 04 00 2F 00 96 00 41 00 15 00 12 00 1A 00 09 00 14
00 11 00 19 00 08 00 06 C0 10 C0 06 C0 15 C0 0B C0 01 00 02 00 01 00 FF 01 00 00 12 00 23 00 00 00 0F 00 01 01 00 0E 00 05 00 02 00 01 00
-> It is exactly what the client receive (wireshark comparison)
The client respond with a 835 byte long UDP packet :
16 FE FF 00 00 00 00 00 00 00 0A 00 62 02 00 00 56 00 00 00 00 00 00 00 56 FE FF 5D AC 4B 27 AD 56 5B 30 A5 4A 12 D9 B3 03 67 71 A2 BE D4 BF FF 1E D8 F1
F8 A5 44 87 E7 E5 C2 F3 20 00 24 63 68 07 6E 0D 28 71 A9 FE 33 C7 E1 65 34 ED 66 98 0D D2 60 F1 ED E9 30 F5 46 4B 21 62 6C C0 13 00 00 0E 00 0E 00 05
00 02 00 01 00 FF 01 00 01 00 16 FE FF 00 00 00 00 00 00 00 0B 01 AF 0B 00 01 A3 00 01 00 00 00 00 01 A3 00 01 A0 00 01 9D 30 82 01 99 30 82 01 02 A0
03 02 01 02 02 04 01 AB 27 96 30 0D 06 09 2A 86 48 86 F7 0D 01 01 0B 05 00 30 11 31 0F 30 0D 06 03 55 04 03 13 06 57 65 62 52 54 43 30 1E 17 0D 31 35
30 31 31 34 31 39 31 36 33 38 5A 17 0D 31 35 30 32 31 33 31 39 31 36 33 38 5A 30 11 31 0F 30 0D 06 03 55 04 03 13 06 57 65 62 52 54 43 30 81 9F 30 0D
06 09 2A 86 48 86 F7 0D 01 01 01 05 00 03 81 8D 00 30 81 89 02 81 81 00 E5 02 17 70 0C A4 81 47 D4 B0 5D 3D 06 2D 7C 97 D1 13 A1 C3 D4 D2 5D 31 98 90
16 7B 45 CC 8A 8F 5C DA 27 A1 24 E4 06 80 28 12 33 3A 4B B9 E3 F7 25 96 00 E3 DF 02 28 EB 8E B1 4C 6E 57 0C 02 F5 61 EA 12 CF AC 00 9B 4B 8A 3D D1 04
98 77 2F 64 5F CE DE CE 6E 0F 0D CE AA FB 4A 61 00 42 6F 9A 6C 6A 5B 1B 6E 28 9C 08 D6 BC 4C C6 FD 68 18 83 47 44 7E D9 AB F1 6F AC 05 32 A5 8E 1A 61
2F 23 02 03 01 00 01 30 0D 06 09 2A 86 48 86 F7 0D 01 01 0B 05 00 03 81 81 00 92 86 27 43 79 53 55 67 7D 5D 5B C4 C7 BC A1 9A 48 32 88 1A C4 8A 78 B9
B3 30 3F A4 2A 8E 03 7E F2 08 0B 2B D8 BC 15 9B 1F 7D E2 E1 08 DA 20 72 B2 C2 5A 9B 15 E6 84 78 59 89 43 AF F8 A8 6A 28 F6 74 A1 1F 24 6D F7 4B DD F0
5F 61 64 1F 22 22 E9 8C 59 FE 59 43 E7 4D C9 AC 98 F2 A3 EA B2 BB AD 4B 57 39 72 F2 C7 2D 9B 9C A1 6B 79 77 6E 9E 80 F3 E6 E6 E3 4F 4E 1B 5F 18 B2 3D
89 AC C1 6B 16 FE FF 00 00 00 00 00 00 00 0C 00 D3 0C 00 00 C7 00 02 00 00 00 00 00 C7 03 00 17 41 04 16 79 2E A6 BC 06 43 F0 98 C5 21 04 CE C0 3B 3A
A6 E8 7C AD B9 CC 59 3D 96 DA C4 50 8B 9F F2 05 E0 D3 25 C3 71 80 18 B5 30 9B E7 22 8B DF DB 2D 31 46 69 1B E3 CB 2E 48 BF 06 76 69 3E A2 2D 0D 00 80
56 4C 98 CF 17 DB 17 06 7E 77 A5 EA AA 5B E5 CE 86 B5 19 4F 55 75 6C B0 DC E5 5A B0 D1 3F 05 1F 9E B2 E3 56 CF F5 B4 57 E5 6D 74 C2 2C B6 80 A3 19 FC
5B 5E 53 FA 06 2E CF 41 6E 79 69 B4 4B 7C 8C B2 AB A4 FB E4 BC FB 1E 8E 91 FA 46 00 DF 72 FC 0F 80 FD C5 83 1A 2B EE CC C6 79 EF 96 1C 9C A5 0F BB E2
FF 82 58 6C C3 68 D6 02 A4 C2 09 B6 69 24 DE 71 4D 30 1C D5 23 70 30 9F 7B BD 66 37 16 FE FF 00 00 00 00 00 00 00 0D 00 12 0D 00 00 06 00 03 00 00 00
00 00 06 03 01 40 02 00 00 16 FE FF 00 00 00 00 00 00 00 0E 00 0C 0E 00 00 00 00 04 00 00 00 00 00 00
-> that is well received by the server
Data are well written to the BIO, but after that, SSL_do_handshake still return SSL_ERROR_WANT_READ or SSL_ERROR_WANT_WRITE. Nothing alarming here, we are at the middle of the handshake. But, instead of sending certificate, the next call to janus_dtls_fd_bridge send the first 197 byte long certificate .....
And again and again ..
So is it an openssl issue ? I don't think it is a libnice issue because the data received/send is exactly what we expect to (integrity, i didnt checked the certificate itself).
but if something is not correct with the certificate, openssl must return something different than SSL_ERROR_NONE or SSL_ERROR_WANT_READ or SSL_ERROR_WANT_WRITE, and it is not the case ...
Lorenzo Miniero
Jan 16, 2015, 9:41:41 AM1/16/15
to meetech...@googlegroups.com, wma...@gmail.com
That's weird... is this what you took by adding checks in the code? As you said, a SSL_WANT_READ/WRITE is normal in the handshake phase, as the SSL_read will not return data that can be used by the application. If it really received a response and is not handling it as it should it may indeed be a problem with openssl, even though I never heard of anything like that.
Still abroad so can't look into anything in depth right now.
L.
William MANCON
Jan 16, 2015, 5:53:18 PM1/16/15
to meetech...@googlegroups.com, wma...@gmail.com
Yes, i add check in the code, in dtls.c and i dump data en the screen
void janus_dump_network_packet(char * buf,int len)
{
int i = 0 ;
for(;i<len;i++)
{
printf("%.2X ",(unsigned char)buf[i]) ;
if(i%50 == 0 && i)
printf("\n") ;
}
printf("\n") ;
}
[...]
int ret = SSL_do_handshake(dtls->ssl) ;
int err = SSL_get_error(dtls->ssl, ret) ;
if(err == SSL_ERROR_WANT_READ)
{
JANUS_LOG(LOG_INFO, "[WM] do_handshake ret : %d err : %d \n",ret,err) ;
}
else JANUS_LOG(LOG_INFO, "[WM] HANDSHAKE OK \n") ;
[....]
if(written > 0)
{
JANUS_LOG(LOG_INFO, " Written %d of those bytes on the read BIO...\n", written) ;
janus_dump_network_packet(buf,len) ;
}
[....]
if (read > 0 )
{
JANUS_LOG(LOG_INFO, " ... and read %d of them from SSL...\n", read) ;
janus_dump_network_packet(data,read) ;
}
Output :
[......]
[279036221] >> Going to send DTLS data: 197 bytes
16 FE FF 00 00 00 00 00 00 00 02 00 B8 01 00 00 AC 00 00 00 00 00 00 00 AC FE FF B4 48 05 E8 BE A6 4B 37 81 F0 07 F4 2A BD 32 5A 33 5B 59 47 70 09 42 AC
0F 6F 5C CC A5 17 48 BD 00 00 00 70 C0 14 C0 0A 00 39 00 38 00 88 00 87 C0 19 00 3A 00 89 C0 0F C0 05 00 35 00 84 C0 12 C0 08 00 16 00 13 C0 17 00 1B
C0 0D C0 03 00 0A C0 13 C0 09 00 33 00 32 00 9A 00 99 00 45 00 44 C0 18 00 34 00 9B 00 46 C0 0E C0 04 00 2F 00 96 00 41 00 15 00 12 00 1A 00 09 00 14
00 11 00 19 00 08 00 06 C0 10 C0 06 C0 15 C0 0B C0 01 00 02 00 01 00 FF 01 00 00 12 00 23 00 00 00 0F 00 01 01 00 0E 00 05 00 02 00 01 00
[279036221] >> >> Read 197 bytes from the write_BIO...
[279036221] DTLSv1_get_timeout: 3899
[279036221] DTLSv1_get_timeout: 3798
[279036221] DTLSv1_get_timeout: 3698
[279036221] Looks like DTLS!
Written 835 of those bytes on the read BIO...
16 FE FF 00 00 00 00 00 00 00 0A 00 62 02 00 00 56 00 00 00 00 00 00 00 56 FE FF 9E 8D 1E 77 FA FD 42 E6 F8 EF 8C 5F F7 16 DB 93 20 02 DE CF AB F3 8B A1
FF 59 28 AE E2 E8 CA 26 20 00 24 70 8C 82 3E 1F 3B B5 0F C4 25 18 8E F6 02 15 21 EB 8C 2F 02 7F D0 2B 27 22 A6 AB ED E0 BB C0 13 00 00 0E 00 0E 00 05
00 02 00 01 00 FF 01 00 01 00 16 FE FF 00 00 00 00 00 00 00 0B 01 AF 0B 00 01 A3 00 01 00 00 00 00 01 A3 00 01 A0 00 01 9D 30 82 01 99 30 82 01 02 A0
03 02 01 02 02 04 01 AB 27 96 30 0D 06 09 2A 86 48 86 F7 0D 01 01 0B 05 00 30 11 31 0F 30 0D 06 03 55 04 03 13 06 57 65 62 52 54 43 30 1E 17 0D 31 35
30 31 31 34 31 39 31 36 33 38 5A 17 0D 31 35 30 32 31 33 31 39 31 36 33 38 5A 30 11 31 0F 30 0D 06 03 55 04 03 13 06 57 65 62 52 54 43 30 81 9F 30 0D
06 09 2A 86 48 86 F7 0D 01 01 01 05 00 03 81 8D 00 30 81 89 02 81 81 00 E5 02 17 70 0C A4 81 47 D4 B0 5D 3D 06 2D 7C 97 D1 13 A1 C3 D4 D2 5D 31 98 90
16 7B 45 CC 8A 8F 5C DA 27 A1 24 E4 06 80 28 12 33 3A 4B B9 E3 F7 25 96 00 E3 DF 02 28 EB 8E B1 4C 6E 57 0C 02 F5 61 EA 12 CF AC 00 9B 4B 8A 3D D1 04
98 77 2F 64 5F CE DE CE 6E 0F 0D CE AA FB 4A 61 00 42 6F 9A 6C 6A 5B 1B 6E 28 9C 08 D6 BC 4C C6 FD 68 18 83 47 44 7E D9 AB F1 6F AC 05 32 A5 8E 1A 61
2F 23 02 03 01 00 01 30 0D 06 09 2A 86 48 86 F7 0D 01 01 0B 05 00 03 81 81 00 92 86 27 43 79 53 55 67 7D 5D 5B C4 C7 BC A1 9A 48 32 88 1A C4 8A 78 B9
B3 30 3F A4 2A 8E 03 7E F2 08 0B 2B D8 BC 15 9B 1F 7D E2 E1 08 DA 20 72 B2 C2 5A 9B 15 E6 84 78 59 89 43 AF F8 A8 6A 28 F6 74 A1 1F 24 6D F7 4B DD F0
5F 61 64 1F 22 22 E9 8C 59 FE 59 43 E7 4D C9 AC 98 F2 A3 EA B2 BB AD 4B 57 39 72 F2 C7 2D 9B 9C A1 6B 79 77 6E 9E 80 F3 E6 E6 E3 4F 4E 1B 5F 18 B2 3D
89 AC C1 6B 16 FE FF 00 00 00 00 00 00 00 0C 00 D3 0C 00 00 C7 00 02 00 00 00 00 00 C7 03 00 17 41 04 16 79 2E A6 BC 06 43 F0 98 C5 21 04 CE C0 3B 3A
A6 E8 7C AD B9 CC 59 3D 96 DA C4 50 8B 9F F2 05 E0 D3 25 C3 71 80 18 B5 30 9B E7 22 8B DF DB 2D 31 46 69 1B E3 CB 2E 48 BF 06 76 69 3E A2 2D 0D 00 80
C7 D2 E7 66 2E 01 8E FC 38 D4 F7 5E FB 58 27 D0 17 F1 CB 42 89 75 56 1E A2 34 AB 83 C2 C7 C3 53 57 FF 31 8B 56 32 74 F9 CF D2 06 7F 88 02 19 0E 34 0F
57 7B 84 A7 AD A5 00 64 1F 13 F9 24 00 D9 BF 22 46 C5 E9 1C 48 CC 33 25 77 F2 DD FB 20 7C 0B 6D 33 05 16 61 A6 61 75 0A 40 5F 97 CA 7B 3B EB 87 6C 8C
A8 A9 39 25 14 8C FD 43 0F 15 FC 56 8D 4E A8 86 11 19 BD A2 72 18 98 58 FB 17 A0 3F 16 FE FF 00 00 00 00 00 00 00 0D 00 12 0D 00 00 06 00 03 00 00 00
00 00 06 03 01 40 02 00 00 16 FE FF 00 00 00 00 00 00 00 0E 00 0C 0E 00 00 00 00 04 00 00 00 00 00 00
... and read -1 of them from SSL...
[WM] do_handshake ret : -1 err : 2
William MANCON
Jan 17, 2015, 6:07:38 AM1/17/15
to meetech...@googlegroups.com, wma...@gmail.com
I'm maybe missing something here :
[3595306136] Component state changed for component 1 in stream 1: 3 (connected)
[3595306136] New selected pair for component 1 in stream 1: 1 <-> 1
[3595306136] Component is ready enough, starting DTLS handshake...
[3595306136] Setting connect state (DTLS client)
[3595306136] >> Going to send DTLS data: 197 bytes
16 FE FF 00 00 00 00 00 00 00 00 00 B8 01 00 00 AC 00 00 00 00 00 00 00 AC FE FF BA A8 FE 1F D6 DB A6 ED 5C 7E 3D 0C 9C 0D 88 8B 41 DA 28 D9 14 AF 86 F2
76 D1 17 94 1B 5C 47 6C 00 00 00 70 C0 14 C0 0A 00 39 00 38 00 88 00 87 C0 19 00 3A 00 89 C0 0F C0 05 00 35 00 84 C0 12 C0 08 00 16 00 13 C0 17 00 1B
C0 0D C0 03 00 0A C0 13 C0 09 00 33 00 32 00 9A 00 99 00 45 00 44 C0 18 00 34 00 9B 00 46 C0 0E C0 04 00 2F 00 96 00 41 00 15 00 12 00 1A 00 09 00 14
00 11 00 19 00 08 00 06 C0 10 C0 06 C0 15 C0 0B C0 01 00 02 00 01 00 FF 01 00 00 12 00 23 00 00 00 0F 00 01 01 00 0E 00 05 00 02 00 01 00
[3595306136] >> >> Read 197 bytes from the write_BIO...
[3595306136] Creating retransmission timer with ID 4
Got a HTTP OPTIONS request on /janus/897197348/3595306136...
... Just parsing headers for now...
Request completed, freeing data
[WARN] [3595306136] Missing valid SRTP session (packet arrived too early?), skipping...
-> here The first 835 byte long from the client (hello, certificate ......done) was skipped. But why ? It seems to be ok according to the network dump (server side)
-> The client send it again, it will be received just after
[3595306136] DTLSv1_get_timeout: 899
[3595306136] DTLSv1_get_timeout: 799
Got a HTTP POST request on /janus/897197348/3595306136...
... Just parsing headers for now...
Got a HTTP POST request on /janus/897197348/3595306136...
... parsing request...
Session: 897197348
Handle: 3595306136
Processing POST data (application/json)...
-- Uploaded data (79 bytes)
-- Data we have now (79 bytes)
Got a HTTP POST request on /janus/897197348/3595306136...
... parsing request...
Session: 897197348
Handle: 3595306136
Processing POST data (application/json)...
Done getting payload, we can answer
{"janus":"trickle","candidate":{"completed":true},"transaction":"xIkR2DZv4q4U"}
No more remote candidates for handle 3595306136!
What happend here ?
Request completed, freeing data
Ok the client send the 835 byte long packet again, but this time, it's not skipped.
[3595306136] Looks like DTLS!
Written 835 of those bytes on the read BIO...
16 FE FF 00 00 00 00 00 00 00 00 00 62 02 00 00 56 00 00 00 00 00 00 00 56 FE FF 7B 12 7D 7B D1 FC ED E5 E2 11 FA A2 8C 55 FE 07 5C A1 17 82 64 CC BB 89
79 B5 E9 36 72 4A BC 5A 20 00 24 2E B9 ED 57 DA 61 A6 FA 63 0D 57 4D ....................[...]
I'm not sure there is a pb with that, because the packet is exactly the same, and in the DTLS handshake process, the BIO seen the Client hello, and after this packet Server hello, Certificate, Server Key exchange, Certificate Request, Server hello done.
Thanks again... ;)
William MANCON
Jan 18, 2015, 6:08:48 AM1/18/15
to meetech...@googlegroups.com, wma...@gmail.com
I tried with the last version of openssl, but same result.
I Don't know how to investigate deeper. In openssl sources ? ....
Weird....
Lorenzo Miniero
Jan 18, 2015, 7:05:00 AM1/18/15
to meetech...@googlegroups.com, wma...@gmail.com
William MANCON
Jan 19, 2015, 10:44:55 PM1/19/15
to meetech...@googlegroups.com, wma...@gmail.com
Ok, i got it.
Open dtls.c and just after line 135, add : SSL_CTX_set_read_ahead(ssl_ctx,1) ;
make, make install and try. It works very well for me.
related to https://github.com/meetecho/janus-gateway/issues/132 and maybe https://github.com/meetecho/janus-gateway/issues/134
Lorenzo Miniero
Jan 20, 2015, 4:26:51 AM1/20/15
to meetech...@googlegroups.com, wma...@gmail.com
Thanks for the heads up, and sorry again for this late reply (just got back to the office today).
That's weird, I was pretty sure we already had the read-ahead stuff for DTLS in the code... I'm wondering whether this was accidently removed in some revision, or if I'm actually remembering this wrong. Anyway, I'll notify the two issues about the fix and then commit it, hoping it will indeed fix it for everybody.
Thanks for your patience and help!
Lorenzo
Ivan Dubynets
May 22, 2017, 3:19:19 AM5/22/17
to meetecho-janus
Hi Lorenzo,
We also faced issue with DTLS session timeout.
The connection happens, but sometimes it takes huge of time (5-15 mins).
This is server side log with debug_level = 5
Do you have ideas what causes this problem?
Thanks,
Ivan
On Wednesday, January 14, 2015 at 12:07:43 PM UTC+2, William MANCON wrote:
On Wednesday, January 14, 2015 at 12:07:43 PM UTC+2, William MANCON wrote:
Hi Lorenzo,I installed recently janus on a new serveur and i can't get it to work..Could you help me to understand the pb ?Here is my log : http://pastebin.com/ERALNdvaEverything seems to be ok with signaling, the negociation (offer/answer..) until browser or janus need to send audio or video data.There is NO network filtering on server side (iptables...).On the client side, with the echo test plugin, (or mcu..) the audio or video data is never sent. After negociation, the client try to exchange the DTLS certificate but no success :614 127.902451000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client Hello627 129.150940000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication673 154.168432000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication719 187.843888000 10.42.0.77 92.202.78.142 DTLSv1.0 153 Server Hello720 187.844185000 10.42.0.77 92.202.78.142 DTLSv1.0 507 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]721 187.845172000 10.42.0.77 92.202.78.142 DTLSv1.0 99 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]722 187.845268000 10.42.0.77 92.202.78.142 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done723 187.892663000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client Hello754 204.590344000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication798 229.152028000 92.202.78.142 10.42.0.77 STUN 70 Binding Indication849 247.846145000 10.42.0.77 92.202.78.142 DTLSv1.0 153 Server Hello850 247.846484000 10.42.0.77 92.202.78.142 DTLSv1.0 507 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]851 247.846565000 10.42.0.77 92.202.78.142 DTLSv1.0 99 Certificate[Reassembly error, protocol DTLS: New fragment overlaps old data (retransmission?)]852 247.846638000 10.42.0.77 92.202.78.142 DTLSv1.0 322 Server Key Exchange, Certificate Request, Server Hello Done853 247.909974000 92.202.78.142 10.42.0.77 DTLSv1.0 239 Client HelloThat is strange, the certificate (certs by default) is the same on the test machine, and everything is ok. On the new server even if there is a network issue, i can't understand why it is causing probleme with the DTLS certificate exchange.With the video MCU, when i close the session, nothing strange appears, ressources a freed etc. Janus always record audio and video empty files (15 o).Do you have an idea ?Thank you ;)
Lorenzo Miniero
May 22, 2017, 5:23:56 AM5/22/17
to meetecho-janus
It's not the logs you should look at, but the Admin API or events from the handlers. Besides, you should try capturing the traffic for that exchange to check why that happens. If it takes so long, it's either a problem with too many DTLS retransmissions during the handshake (the timeout increases exponentially), or possibly a different view between browser and Janus on whether ICE succeeded or not (Janus might think it did and the browser not, thus leading to Janus sending DTLS handshake messages that the browser will ignore until ICE is fine there too). All things you'll need to look into by checking Admin API/Event Handlers and, at the same time, statistics collected on the browser that's giving issues (e.g., in terms of ICE state).
L.
Reply all
Reply to author
Forward
0 new messages