Bugzilla

Reporter

Comment 2

•

10 years ago

Attached file test_dataChannel_basicAudio.html 32-bit log — Details

Log from "mach test dom/media/tests/mochitest/test_dataChannel_basicAudio.html" on 32-bit dbg with max logging level.

I removed pldhash size complaints since it's reasonable for those to differ on win64.

Reporter

Comment 3

•

10 years ago

Attached file test_dataChannel_basicAudio.html 64-bit log — Details

Log from "mach test dom/media/tests/mochitest/test_dataChannel_basicAudio.html" on 64-bit dbg with max logging level.

I closed the browser window at 0:50 when it became clear that the test wasn't going to finish on its own.

Reporter

Comment 4

•

10 years ago

I want to debug this but there's another bug that I really ought to be working on.

:jesup are you interested in taking a look? This bug is the last remaining unknown for the win64 tests on Date. If you can't/don't get to this, then I'll come back to it on my next event loop.

Flags: needinfo?(rjesup)

Comment 5

•

10 years ago

The important piece in the 64bit log is IMHO this:

0:18.42 4380[2212000]: Flow[87a6e8bd765ad168:2,rtp(none)]; Layer[dtls]: PacketReceived(135)
0:18.42 4380[2212000]: Flow[87a6e8bd765ad168:2,rtp(none)]; Layer[ice]:  SendPacket(15) succeeded
0:18.42 4380[2212000]: Flow[87a6e8bd765ad168:2,rtp(none)]; Layer[dtls]: SSL handshake error -12246

For whatever reason the DTLS handshake fails and there is currently no way to inform the JS side about it.

And the log file from the initial report is full of "SSL handshake error". So it seems like we have a DTLS problem on Win64.

@jesup: who would be the best person to look into this, besides Ekr?

Randell Jesup [:jesup] (needinfo me)

Comment 6

•

10 years ago

@ekr: Looks like DTLS is not working on Win64. Any idea? Who could help debugging this?

Flags: needinfo?(rjesup) → needinfo?(ekr)

Updated

•

10 years ago

Group: media-core-security

Comment 7

•

10 years ago

OK, so we are doing four SendPacket(135)s and yet there are only four DTLS connections:

 0:17.74 4380[2212000]: Setting up DTLS as client
 0:17.83 4380[2212000]: Setting up DTLS as client
 0:18.23 4380[2212000]: Setting up DTLS as server
 0:18.38 4380[2212000]: Setting up DTLS as server

This is suspicious since the 135s are likely ClientHellos which is what you would expect if both sides thought they were Clients.

Nils: can you make this happen in your machine? If so, I've got some suggestions for places to look.

Flags: needinfo?(ekr)

Reporter

Comment 8

•

10 years ago

In case it helps, the test failure is only on debug builds. (Or maybe the underlying issue is present on opt builds and goes unnoticed, I don't know)

Comment 9

•

10 years ago

Interesting.

Comment 10

•

10 years ago

(In reply to Eric Rescorla (:ekr) from comment #7) 
> This is suspicious since the 135s are likely ClientHellos which is what you
> would expect if both sides thought they were Clients.
> 
> Nils: can you make this happen in your machine? If so, I've got some
> suggestions for places to look.

To MT and me it looks like both ends get setup as DTLS client and server. The server side is missing an ICE packet so that the ICE connection is not open yet when it receives the client HELLO and therefore discards it. But then the server side suddenly sends this 135 bytes, which look like a client HELLO and that obviously confuses the client side.

David: How do I build this locally? Could you try to re-run the 64bit test with these env variables set SSLTRACE=1 and SSLDEBUG=1?

Flags: needinfo?(dmajor)

Comment 11

•

10 years ago

(In reply to Nils Ohlmeier [:drno] from comment #10)
> (In reply to Eric Rescorla (:ekr) from comment #7) 
> > This is suspicious since the 135s are likely ClientHellos which is what you
> > would expect if both sides thought they were Clients.
> > 
> > Nils: can you make this happen in your machine? If so, I've got some
> > suggestions for places to look.
> 
> To MT and me it looks like both ends get setup as DTLS client and server.

Yes, I agree.

That's what I cut and pasted above.


> The server side is missing an ICE packet so that the ICE connection is not
> open yet when it receives the client HELLO and therefore discards it. But
> then the server side suddenly sends this 135 bytes, which look like a client
> HELLO and that obviously confuses the client side.

Yes, that's what confuses me as well.

> 
> David: How do I build this locally? Could you try to re-run the 64bit test
> with these env variables set SSLTRACE=1 and SSLDEBUG=1?

Comment 12

•

10 years ago

Can we put a breakpoint in TLDtls::SetRole() to see if it's being called in some weirdly unexpected place?

Reporter

Comment 13

•

10 years ago

Attached file 64-bit SSLTRACE=1 SSLDEBUG=1 — Details

Flags: needinfo?(dmajor)

Reporter

Comment 14

•

10 years ago

> David: How do I build this locally?

I used "start-shell-msvc2010-x64.bat" and the mozconfig at browser/config/mozconfigs/win64/debug.

Feel free to use the Date branch as a playground if you need it. It does x64 builds and tests (the test results are displayed next to the 32-bit ones).

Comment 15

•

10 years ago

(In reply to David Major [:dmajor] from comment #14)
> > David: How do I build this locally?
> 
> I used "start-shell-msvc2010-x64.bat" and the mozconfig at
> browser/config/mozconfigs/win64/debug.
> 
> Feel free to use the Date branch as a playground if you need it. It does x64
> builds and tests (the test results are displayed next to the 32-bit ones).

Unfortunately the other log files was not as helpful as we were hoping.
Thanks for the pointer (without I did not succeed to compile 64bit so far). I'm going to give it a try with a local build later.

Reporter

Comment 16

•

10 years ago

(In reply to Eric Rescorla (:ekr) from comment #12)
> Can we put a breakpoint in TLDtls::SetRole() to see if it's being called in
> some weirdly unexpected place?

I got the same four hits on both win32 and win64. Two client followed by two server, same stacks.

Daniel Veditz [:dveditz]

Updated

•

10 years ago

Group: media-core-security → core-security

Comment 17

•

10 years ago

I have a 64bit build running locally now as well, which hangs at test_dataChannel_basicAudio.html.
David can you confirm that if you run just test_peerConnection_basicAudio.html it passes?

Flags: needinfo?(dmajor)

Reporter

Comment 18

•

10 years ago

Confirmed, test_peerConnection_basicAudio.html passes.

Flags: needinfo?(dmajor)

Comment 19

•

10 years ago

Here is the confirmation for our theory from my logs:

 0:21.89 2014-07-15 03:48:28.950000 UTC - 3860[2012000]: Setting up DTLS as client
 0:22.43 1796: SSL3[501600656]: send client_hello handshake
 0:22.51 2014-07-15 03:48:29.558000 UTC - 3860[2012000]: Setting up DTLS as server
 0:22.70 1796: SSL3[501602672]: send client_hello handshake

Comment 20

•

10 years ago

OK, I have a partial theory here. If you look at the code, the client/server switch
keys off the same value, role_, but using the opposite test.

role_ is an enum with only two values, CLIENT and SERVER.

Here is the switch
for whether we set up as the client or the server, where we test against CLIENT:
http://dxr.mozilla.org/mozilla-central/source/media/mtransport/transportlayerdtls.cpp#469

and here is the switch for how we reset the handshake, where we test against SERVER
http://dxr.mozilla.org/mozilla-central/source/media/mtransport/transportlayerdtls.cpp#571

Note that this is the same function.

If role_ somehow got set to some value that we neither client nor server,
(E.g., due to memory error) then we would take the SERVER arm for the first
of these branches and the CLIENT arm in the second one, which would be consistent
with what we are seeing.

Note that we initialize the value in the ctor at:
http://dxr.mozilla.org/mozilla-central/source/media/mtransport/transportlayerdtls.h#50

And the only place that seems to call SetRole() is at:
http://dxr.mozilla.org/mozilla-central/source/media/webrtc/signaling/src/media/VcmSIPCCBinding.cpp#3148

Nils: I would suggest that you put a check in TransportLayerDtls::Setup() where you
print out the value of role_ and see if it's neither CLIENT nor SERVER. If so,
then you'll need to track down where it gets messed up. Perhaps you can track
it down with printfs/asserts if that's what the problem is here.

I'm not totally in love with this theory since it would seem to imply that only
one side is getting messed up, which is weird. So, maybe something else is happening,
but at least this seems like a place to start.

Comment 21

•

10 years ago

Wasted some time today with chasing a false alarm. Martin and me had the same theory/observation on Friday. Will put instrumentation around that tomorrow.

A few observations:
- this happens with all data channel tests, but not with the peerConnection tests
- the test_dataChannel_bug1013809.html initialized first the server side then the client and it looks like the server side sends a client_hello even in that case (which probably means the role_ being initialized wrong from the get go):

 0:24.36 2014-07-15 05:30:57.212000 UTC - 3012[2012000]: Setting up DTLS as server
 0:24.62 3548: SSL3[401248416]: send client_hello handshake
 0:24.86 2014-07-15 05:30:57.761000 UTC - 3012[2012000]: Setting up DTLS as server
 0:24.87 3548: SSL3[188835632]: send client_hello handshake
 0:26.25 2014-07-15 05:30:59.151000 UTC - 3012[2012000]: Setting up DTLS as client
 0:26.26 3548: SSL3[161130720]: send client_hello handshake
 0:26.61 2014-07-15 05:30:59.516000 UTC - 3012[2012000]: Setting up DTLS as client
 0:26.62 3548: SSL3[175048256]: send client_hello handshake

Reporter

Comment 22

•

10 years ago

Aha! The second test is: cmp dword ptr [rsi+0E8h],ebx

Where ebx is supposed to be 1, but it's actually garbage due to bug 1025729.

I've applied the NSS patch and it fixes test_dataChannel_basicAudio.html. I'm going to bet it fixes the rest of them too...

Reporter

Comment 23

•

10 years ago

Let's see how this turns out: https://tbpl.mozilla.org/?tree=Date&rev=2a11c3906c7e

I should have put two and two together since I've hit the rbx issue before. Sorry for the time waste.

Andrew McCreight [:mccr8]

Comment 24

•

10 years ago

Attached patch Use the same check in DTLS init — Details — Splinter Review

Try run: https://tbpl.mozilla.org/?tree=Try&rev=ce168d2806b2

Attachment #8456257 - Flags: review?(ekr)

Comment 25

•

10 years ago

This sounds like we're reading random garbage, so I'm going to set this to sec-high.

Keywords: sec-high

Andrew McCreight [:mccr8]

Comment 26

•

10 years ago

I'm not trying to debate the security level, but as I understand the situation,
we have code here which is correctly trying to read some memory value
(in this case a register) which has been independently trashed. so this is
a side effect of that other problem, which might manifest other side effects
in other cases, right?

Updated

•

10 years ago

Depends on: 1025729

Updated

•

10 years ago

Attachment #8456257 - Flags: review?(ekr) → review?(martin.thomson)

Martin Thomson [:mt:]

Comment 27

•

10 years ago

Comment on attachment 8456257 [details] [diff] [review]
Use the same check in DTLS init

Review of attachment 8456257 [details] [diff] [review]:
-----------------------------------------------------------------

I'm not sure that we really need to land this, if it's down to a corruption issue elsewhere.

It is fine though.

Attachment #8456257 - Flags: review?(martin.thomson) → review+

Reporter

Comment 28

•

10 years ago

1025729 has landed in m-c and has fixed this issue. Do you still want to check in the DTLS change?

Flags: needinfo?(drno)

Comment 29

•

10 years ago

If it works without this change it might be better to not touch a working system. So let close this issue if it works now for you.

Flags: needinfo?(drno)

Reporter

Updated

•

10 years ago

Status: NEW → RESOLVED

Closed: 10 years ago

Resolution: --- → FIXED

Reporter

Updated

•

10 years ago

Target Milestone: --- → mozilla33

Benjamin Smedberg

Comment 30

•

10 years ago

Does this bug need to remain private?

Flags: needinfo?(drno)