Closed Bug 1594673 Opened 8 months ago Closed 8 months ago

High-frequency /webrtc/RTCDataChannelEvent-constructor.html | unable to find test window

Categories

(Core :: WebRTC, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla72
Tracking Status
firefox72 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: dminor)

References

(Regression)

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered])

Attachments

(1 file)

Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=275009900&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/P0h2ISvqRv-YyfNfYfBuRg/runs/0/artifacts/public/logs/live_backing.log


[task 2019-11-07T07:31:43.483Z] 07:31:43 INFO - PID 2300 | [Child 1108: Main Thread]: D/DataChannel 0DC7D820(0DC7D760): OnChannelClosed - Dispatching
[task 2019-11-07T07:31:43.484Z] 07:31:43 INFO - PID 2300 | [Parent 4700, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:43.484Z] 07:31:43 INFO - PID 2300 | [Child 1108, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:53.948Z] 07:31:53 INFO - PID 2300 | [Parent 4700, Gecko_IOThread] WARNING: file z:/task_1573103194/build/src/ipc/chromium/src/base/process_util_win.cc, line 160
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - Traceback (most recent call last):
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 627, in _run
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - self.result = True, self.func(self.protocol, self.url, self.timeout)
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 735, in do_testharness
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - timeout=10self.timeout_multiplier)
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 226, in get_test_window
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - raise Exception("unable to find test window")
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING - Exception: unable to find test window
[task 2019-11-07T07:31:54.063Z] 07:31:54 WARNING -
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - TEST-UNEXPECTED-ERROR | /webrtc/RTCDataChannelEvent-constructor.html | unable to find test window
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - Traceback (most recent call last):
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 627, in _run
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - self.result = True, self.func(self.protocol, self.url, self.timeout)
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 735, in do_testharness
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - timeout=10
self.timeout_multiplier)
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - File "Z:\task_1573108755\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 226, in get_test_window
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - raise Exception("unable to find test window")
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - Exception: unable to find test window
[task 2019-11-07T07:31:54.064Z] 07:31:54 INFO - TEST-INFO took 10744ms
[task 2019-11-07T07:31:54.071Z] 07:31:54 INFO - PID 2300 | 1573111914056 Marionette INFO Stopped listening on port 49446
[task 2019-11-07T07:31:54.166Z] 07:31:54 INFO - PID 2300 | [Parent 4700, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.166Z] 07:31:54 INFO - PID 2300 | [Child 2456, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.166Z] 07:31:54 INFO - PID 2300 | [Child 2456, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.167Z] 07:31:54 INFO - PID 2300 | [Parent 4700, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.174Z] 07:31:54 INFO - PID 2300 | [Child 4068, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.174Z] 07:31:54 INFO - PID 2300 | [Child 4068, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line[Child 6004, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.313Z] 07:31:54 INFO - PID 2300 | [Child 600[Parent 4700, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.313Z] 07:31:54 INFO - PID 2300 | [Child 3844, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1573103194/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
[task 2019-11-07T07:31:54.600Z] 07:31:54 INFO - PID 2300 | [Child 3844, Chrome_ChildThread] W
[task 2019-11-07T07:31:54.621Z] 07:31:54 INFO - Browser exited with return code 0
[task 2019-11-07T07:31:54.621Z] 07:31:54 INFO - PROCESS LEAKS None
[task 2019-11-07T07:31:54.622Z] 07:31:54 INFO - Closing logging queue
[task 2019-11-07T07:31:54.622Z] 07:31:54 INFO - queue closed
[task 2019-11-07T07:31:54.641Z] 07:31:54 INFO - Setting up ssl
[task 2019-11-07T07:31:54.696Z] 07:31:54 INFO - certutil |
[task 2019-11-07T07:31:54.743Z] 07:31:54 INFO - certutil |
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO - certutil |
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO - Certificate Nickname Trust Attributes
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO - SSL,S/MIME,JAR/XPI
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO -
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO - web-platform-tests CT,,
[task 2019-11-07T07:31:54.763Z] 07:31:54 INFO -
[task 2019-11-07T07:31:54.822Z] 07:31:54 INFO - Application command: Z:\task_1573108755\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile c:\users\task_1573108755\appdata\local\temp\tmpa04js6.mozrunner
[task 2019-11-07T07:31:54.829Z] 07:31:54 INFO - Starting runner
[task 2019-11-07T07:31:55.364Z] 07:31:55 INFO - PID 3440 | 1573111915358 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-11-07T07:31:55.364Z] 07:31:55 INFO - PID 3440 | 1573111915358 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
[task 2019-11-07T07:31:55.364Z] 07:31:55 INFO - PID 3440 | 1573111915359 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-11-07T07:31:55.365Z] 07:31:55 INFO - PID 3440 | 1573111915359 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2019-11-07T07:31:57.030Z] 07:31:57 INFO - PID 3440 | 1573111917027 Marionette INFO Listening on port 49446
[task 2019-11-07T07:31:57.592Z] 07:31:57 INFO - TEST-START | /webrtc/RTCIceCandidate-constructor.html
[task 2019-11-07T07:31:57.607Z] 07:31:57 INFO - Setting pref media.navigator.permission.disabled (true)
[task 2019-11-07T07:31:57.622Z] 07:31:57 INFO - Setting pref privacy.resistFingerprinting.reduceTimerPrecision.jitter (false)
[task 2019-11-07T07:31:57.629Z] 07:31:57 INFO - Setting pref media.navigator.streams.fake (true)
[task 2019-11-07T07:31:57.644Z] 07:31:57 INFO - Setting pref privacy.reduceTimerPrecision (false)
[task 2019-11-07T07:31:57.873Z] 07:31:57 INFO - ..................
[task 2019-11-07T07:31:57.873Z] 07:31:57 INFO - TEST-OK | /webrtc/RTCIceCandidate-constructor.html | took 286ms

This is caused by the changes in Bug 1588817. I also filed Bug 1594018. I ran into this on Try, but I thought I had disabled the problematic test. If this is too high frequency, feel free to back out my changes above. I'll have a look right away.

Regressed by: 1588817
See Also: → 1594018

Looking at the logs, it appears that the test I wanted to disable on windows 7 in https://hg.mozilla.org/mozilla-central/rev/6a7b78f2d462 is still running:

[task 2019-11-07T10:43:12.053Z] 10:43:12 INFO - PID 3760 | (ice/INFO) ICE-PEER(PC:1573123391052000 (id=30064771074 url=http://web-platform.test:8000/webrtc/RTCDataChannel-send.html):default)/STREAM(PC:1573123391052000 (id=30064771074 url=http://web-platform.test:8000/webrtc/RTCDataChannel-send.html) transport-id=transport_0 - 572816fe:1f563f74b15c3830de95a68e9c6e6dd7)/COMP(1)/CAND-PAIR(0f9I): cancelling all pairs but 0f9I|IP4:10.147.40.65:62969/UDP|IP4:10.147.40.65:62971/UDP(host(IP4:10.147.40.65:62969/UDP)|prflx)

I definitely messed up the syntax to disable RTCDataChannel-send.html, but I should just be able to mark RTCDataChannelEvent-constructor.html as intermittent. I've started try jobs for each, I'll see which one is more effective. It's possible that the test after RTCDataChannelEvent-constructor.html will also fail intermittently if the real problem is RTCDataChannel-send.html.

Either I messed up the syntax or the framework doesn't pick up on "unable to find test window" as an error: https://treeherder.mozilla.org/#/jobs?repo=try&revision=e3ae453387bb74672ebc762c53e1ea05689a29b5. Actually disabling the test seems to do the trick though: https://treeherder.mozilla.org/#/jobs?repo=try&revision=70c2f3b5a7b64e33e47b62d61593dd1a5df2e9eb.

Assignee: nobody → dminor
Status: NEW → ASSIGNED

I messed up the syntax the first time around, this actually disables
the test. This was exacerbated by accidentally testing the changes on
win32-opt rather than win32-shippable-opt where the intermittent
occurs.

Pushed by dminor@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/d9a3fbd31fe5
Actually disable RTCDataChannel-send on win32; r=ng
Status: ASSIGNED → RESOLVED
Closed: 8 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla72
You need to log in before you can comment on or make changes to this bug.