py3-mochitest gives Error executing test: ICE Server gone before getting configuration
Categories
(Testing :: Mochitest, defect)
Tracking
(firefox84 fixed)
| Tracking | Status | |
|---|---|---|
| firefox84 | --- | fixed |
People
(Reporter: pehrsons, Assigned: bwc)
References
(Regression)
Details
(Keywords: regression)
Attachments
(2 files, 1 obsolete file)
With python3 running mochitests, and the new twisted version setup for py3 in bug 1668097 I'm getting errors for 4 peerconnection mochitests when running ./mach mochitest dom/media/webrtc/tests/mochitest/test_peerConnection_ locally (Ubuntu 20.04):
Overall Summary
===============
mochitest-plain
~~~~~~~~~~~~~~~
Ran 44584 checks (131 asserts, 44316 subtests, 137 tests)
Expected results: 44574
Skipped: 6 tests
Unexpected results: 4
subtest: 4 (4 fail)
Unexpected Results
------------------
dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATRelay.html
FAIL Error executing test: ICE Server gone before getting configuration
SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
runTestWhenReady/<@dom/media/webrtc/tests/mochitests/head.js:475:9
dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATRelayTCP.html
FAIL Error executing test: ICE Server gone before getting configuration
SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
runTestWhenReady/<@dom/media/webrtc/tests/mochitests/head.js:475:9
dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATSrflx.html
FAIL Error executing test: ICE Server gone before getting configuration
SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
runTestWhenReady/<@dom/media/webrtc/tests/mochitests/head.js:475:9
dom/media/webrtc/tests/mochitests/test_peerConnection_stats_relayProtocol.html
FAIL Error executing test: ICE Server gone before getting configuration
SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
runTestWhenReady/<@dom/media/webrtc/tests/mochitests/head.js:475:9
Traceback (most recent call last):
File "/home/pehrsons/.mozbuild/_virtualenvs/mach/lib/python3.8/site-packages/glean/_subprocess/_process_dispatcher_helper.py", line 34, in <module>
func, args = pickle.loads(base64.b64decode(sys.argv[1]))
File "/home/pehrsons/dev/mozilla-central/build/mach_bootstrap.py", line 504, in __call__
module = self._original_import(name, globals, locals, fromlist, level)
ModuleNotFoundError: No module named 'glean'
FWIW python2 mach mochitest dom/media/webrtc/tests/mochitest/test_peerConnection_ does not result in these unexpected failures.
|
||
Comment 1•5 years ago
|
||
Thanks for the report!
I get a similar but different failure:
0:05.13 TEST_START: dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATRelay.html
0:06.34 GECKO(332416) TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
0:06.34 GECKO(332416) TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
0:06.35 PASS A valid string reason is expected
0:06.35 PASS Reason cannot be empty
0:06.35 PASS A valid string reason is expected
0:06.35 PASS Reason cannot be empty
0:06.38 INFO websocket/process bridge open, starting ICE Server...
Unhandled Error
Traceback (most recent call last):
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/log.py", line 103, in callWithLogger
return callWithContext({"system": lp}, func, *args, **kw)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/log.py", line 86, in callWithContext
return context.call({ILogContext: newCtx}, func, *args, **kw)
0:06.38 INFO ICE Server websocket closed
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/context.py", line 122, in callWithContext
return self.currentContext().callWithContext(ctx, func, *args, **kw)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/context.py", line 85, in callWithContext
return func(*args,**kw)
--- <exception caught here> ---
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
why = selectable.doRead()
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/tcp.py", line 243, in doRead
return self._dataReceived(data)
0:06.38 FAIL Error executing test: ICE Server gone before getting configuration
SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
runTestWhenReady/<@dom/media/webrtc/tests/mochitests/head.js:475:9
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/tcp.py", line 249, in _dataReceived
rval = self.protocol.dataReceived(data)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/txws.py", line 629, in dataReceived
self.parseFrames()
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/txws.py", line 469, in parseFrames
ProtocolWrapper.dataReceived(self, data)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/protocols/policies.py", line 120, in dataReceived
self.wrappedProtocol.dataReceived(data)
File "websocketprocessbridge/websocketprocessbridge.py", line 62, in dataReceived
commands[data][0],
builtins.KeyError: b'iceserver'
Unhandled Error
Traceback (most recent call last):
File "websocketprocessbridge/websocketprocessbridge.py", line 104, in <module>
reactor.run()
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/base.py", line 1283, in run
self.mainLoop()
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/base.py", line 1295, in mainLoop
self.doIteration(t)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/epollreactor.py", line 235, in doPoll
log.callWithLogger(selectable, _drdw, selectable, fd, event)
--- <exception caught here> ---
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/log.py", line 103, in callWithLogger
return callWithContext({"system": lp}, func, *args, **kw)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/log.py", line 86, in callWithContext
return context.call({ILogContext: newCtx}, func, *args, **kw)
0:06.39 GECKO(332416) MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
0:06.39 GECKO(332416) MEMORY STAT | vsize 2328MB | residentFast 119MB | heapAllocated 9MB
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/context.py", line 122, in callWithContext
return self.currentContext().callWithContext(ctx, func, *args, **kw)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/python/context.py", line 85, in callWithContext
return func(*args,**kw)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/posixbase.py", line 627, in _doReadOrWrite
self._disconnectSelectable(selectable, why, inRead)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/posixbase.py", line 258, in _disconnectSelectable
selectable.connectionLost(failure.Failure(why))
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/internet/tcp.py", line 327, in connectionLost
protocol.connectionLost(reason)
File "/home/gbrown/objdirs/firefox/_virtualenvs/init_py3/lib/python3.8/site-packages/twisted/protocols/policies.py", line 125, in connectionLost
self.wrappedProtocol.connectionLost(reason)
File "websocketprocessbridge/websocketprocessbridge.py", line 68, in connectionLost
self.processSide.socketGone()
File "websocketprocessbridge/websocketprocessbridge.py", line 44, in socketGone
self.transport.loseConnection()
builtins.AttributeError: 'NoneType' object has no attribute 'loseConnection'
0:06.39 TEST_END: Test OK. Subtests passed 4/5. Unexpected 1
0:06.39 INFO TEST-START | Shutdown
0:06.39 INFO Passed: 4
0:06.39 INFO Failed: 1
0:06.39 INFO Todo: 0
0:06.39 INFO Mode: e10s
|
|
||
Comment 2•5 years ago
|
||
I have promising work in progress that fixes iceserver and webprocessocketbridge for me; I'm still unsure about the original error reported here, but fingers crossed...
|
|
||
Comment 3•5 years ago
|
||
This allows me to run iceserver and websocketprocessbridge in mochitests under python 3. Some
tests still fail for me, so follow-up is likely required, but these changes at least allow
the servers to run without obvious failures.
|
|
||
Updated•5 years ago
|
|
|
||
Comment 5•5 years ago
|
||
| bugherder | ||
|
|
||
Comment 6•5 years ago
|
||
Now, running 'mach mochitest dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATRelay.html', I see the test hang after:
0:10.65 TEST_START: dom/media/webrtc/tests/mochitests/test_peerConnection_basicAudioNATRelay.html
0:11.83 GECKO(470668) TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
0:11.83 GECKO(470668) TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
0:11.84 PASS A valid string reason is expected
0:11.84 PASS Reason cannot be empty
0:11.84 PASS A valid string reason is expected
0:11.84 PASS Reason cannot be empty
0:11.87 INFO websocket/process bridge open, starting ICE Server...
(The test passes with 'mach test ...', which still uses python2.)
Debugging, I find outReceived() is called with data:
[{"urls":["stun:localhost", "stun:localhost?transport=tcp"]}, {"username":"foo","credential":"bar","urls": ["turn:localhost", "turn:localhost?transport=tcp" ] }]
The splitlines() fails, but that can be rectified with another six.ensure_str()...but the test still hangs.
|
|
||
Comment 7•5 years ago
|
||
Sorry for the delay here. I've looked at this a few times, but never seem to make progress.
As in the previous comment, under python 2, with 'mach test ...', tests using iceserver.py pass, but under python 3, with 'mach mochitest ...', tests fail.
Under python 3, I see outReceived() called with the correct data, and have verified that line is passed to self.socketSide.transport.write(line), at
...but the data is not received at
:bwc -- Do you remember how this works? Any suggestions for further debugging?
|
Assignee | |
Comment 8•5 years ago
|
||
Does the version of twisted we're using (10.2.0) support python 3? Let me see what happens when I grab more recent versions of our packages locally...
|
|
Assignee | |
Comment 9•5 years ago
|
||
While I work on this, can we get the ball rolling on impounding more recent versions of the stuff in here?
|
|
||
Comment 10•5 years ago
|
||
With 'mach mochitest' / python 3, mach uses
|
|
Assignee | |
Comment 11•5 years ago
|
||
I took a pcap. The ICE server is sending the data, and then Firefox immediately closes the TCP connection, so I doubt this is a problem in the python code. Let me try to bisect this.
|
|
Assignee | |
Comment 12•5 years ago
|
||
Looks like there's some sort of escaping problem, probably in txws:
python2
0000 02 00 00 00 45 00 00 d9 00 00 40 00 40 06 00 00 ....E.....@.@...
0010 7f 00 00 01 7f 00 00 01 1f ff c1 d1 bc a0 1c 85 ................
0020 02 e9 31 aa 80 18 18 e2 fe cd 00 00 01 01 08 0a ..1.............
0030 70 80 9f 98 70 80 9e 3a 81 7e 00 a1 5b 7b 22 75 p...p..:.~..[{"u
0040 72 6c 73 22 3a 5b 22 73 74 75 6e 3a 6c 6f 63 61 rls":["stun:loca
0050 6c 68 6f 73 74 22 2c 20 22 73 74 75 6e 3a 6c 6f lhost", "stun:lo
0060 63 61 6c 68 6f 73 74 3f 74 72 61 6e 73 70 6f 72 calhost?transpor
0070 74 3d 74 63 70 22 5d 7d 2c 20 7b 22 75 73 65 72 t=tcp"]}, {"user
0080 6e 61 6d 65 22 3a 22 66 6f 6f 22 2c 22 63 72 65 name":"foo","cre
0090 64 65 6e 74 69 61 6c 22 3a 22 62 61 72 22 2c 22 dential":"bar","
00a0 75 72 6c 73 22 3a 20 5b 22 74 75 72 6e 3a 6c 6f urls": ["turn:lo
00b0 63 61 6c 68 6f 73 74 22 2c 20 22 74 75 72 6e 3a calhost", "turn:
00c0 6c 6f 63 61 6c 68 6f 73 74 3f 74 72 61 6e 73 70 localhost?transp
00d0 6f 72 74 3d 74 63 70 22 20 5d 20 7d 5d ort=tcp" ] }]
The websocket frame is 81 7e 00 a1 here.
python 3:
0000 02 00 00 00 45 00 00 e2 00 00 40 00 40 06 00 00 ....E.....@.@...
0010 7f 00 00 01 7f 00 00 01 1f ff fe fd 95 31 36 4b .............16K
0020 8b 53 69 fa 80 18 18 e2 fe d6 00 00 01 01 08 0a .Si.............
0030 70 70 f5 bc 70 70 f4 43 81 7e 62 27 5c 78 30 30 pp..pp.C.~b'\x00
0040 5c 78 61 31 27 5b 7b 22 75 72 6c 73 22 3a 5b 22 \xa1'[{"urls":["
0050 73 74 75 6e 3a 6c 6f 63 61 6c 68 6f 73 74 22 2c stun:localhost",
0060 20 22 73 74 75 6e 3a 6c 6f 63 61 6c 68 6f 73 74 "stun:localhost
0070 3f 74 72 61 6e 73 70 6f 72 74 3d 74 63 70 22 5d ?transport=tcp"]
0080 7d 2c 20 7b 22 75 73 65 72 6e 61 6d 65 22 3a 22 }, {"username":"
0090 66 6f 6f 22 2c 22 63 72 65 64 65 6e 74 69 61 6c foo","credential
00a0 22 3a 22 62 61 72 22 2c 22 75 72 6c 73 22 3a 20 ":"bar","urls":
00b0 5b 22 74 75 72 6e 3a 6c 6f 63 61 6c 68 6f 73 74 ["turn:localhost
00c0 22 2c 20 22 74 75 72 6e 3a 6c 6f 63 61 6c 68 6f ", "turn:localho
00d0 73 74 3f 74 72 61 6e 73 70 6f 72 74 3d 74 63 70 st?transport=tcp
00e0 22 20 5d 20 7d 5d " ] }]
Where we would expect 81 7e 00 a1 as before, we see instead a larger number of bytes beginning with 81 7e, followed by bytes that encode the string b'\x00\xa1'.
|
|
Assignee | |
Comment 13•5 years ago
|
||
It looks like this is a known problem in txws when encoding the payload length:
Unfortunately, it looks like txws is no longer being maintained, and this pull request has sat for nearly 4 years.
|
|
Assignee | |
Comment 14•5 years ago
|
||
It seems that there's now a fork of txws called txws-upgrade that fixes this problem. We might be able to use that.
|
|
||
Comment 15•5 years ago
|
||
Yes - that's promising! Thanks much!
Simply substituting txws-upgrade for txws I managed to run much more of the test. Still not a clean run, but encouraging....
|
|
Assignee | |
Comment 16•5 years ago
|
||
I am working on updating iceserver.py to be both py2 and py3 friendly at the moment. More in a bit.
|
|
||
Comment 17•5 years ago
|
||
|
|
||
Comment 18•5 years ago
|
||
Thanks! Here's my wip, in case it is useful: ^^^
|
|
Assignee | |
Comment 19•5 years ago
|
||
|
|
Assignee | |
Comment 20•5 years ago
|
||
|
|
Assignee | |
Comment 21•5 years ago
|
||
|
|
Assignee | |
Comment 22•5 years ago
|
||
Try looks good.
|
||
Updated•5 years ago
|
|
||
Comment 23•5 years ago
|
||
|
|
||
Comment 24•5 years ago
|
||
| bugherder | ||
|
|
||
Comment 25•5 years ago
|
||
I added leave-open when landing the first patch, but I think we are all done here now?
|
|
Assignee | |
Comment 26•5 years ago
|
||
Yeah.
|
||
Updated•4 years ago
|
Description
•