Closed Bug 1526678 Opened 5 years ago Closed 2 years ago

Intermittent QuantumRender TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/<random>.py | expected OK

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
defect

Tracking

(firefox67 wontfix)

RESOLVED WORKSFORME
Tracking Status
firefox67 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

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

#[markdown(off)]
Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=227415801&repo=try

https://queue.taskcluster.net/v1/task/MNyfT9EXQ3iPgdZjhVgZNw/runs/0/artifacts/public/logs/live_backing.log

14:31:31 INFO - PID 1292 | [GPU 4808, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
14:31:31 INFO - PID 1292 |
14:31:31 INFO - PID 1292 | ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
14:31:31 INFO - PID 1292 |
14:31:31 INFO - PID 1292 |
14:31:31 INFO - PID 1292 | ###!!! [Child][MessageChannel::SendAndWait] Error: Channel error: cannot send/recv
14:31:31 INFO - PID 1292 |
14:31:31 INFO - PID 1292 | 1549722691362 geckodriver::marionette DEBUG Browser process stopped: exit code: 0
14:31:31 INFO - PID 1292 | 1549722691396 webdriver::server DEBUG <- 200 OK {"value":null}
14:31:31 INFO - PID 1292 | 1549722691398 webdriver::server DEBUG -> POST /session {"capabilities": {"alwaysMatch": {"moz:firefoxOptions": {"binary": "Z:\\task_1549719941\\build\\application\\firefox\\firefox.exe", "prefs": {"network.dns.localDomains": "www1.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www1.web-platform.test,www.www2.not-web-platform.test,www2.www2.not-web-platform.test,xn--lve-6lad.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.not-web-platform.test,not-web-platform.test,www1.www.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.web-platform.test,www2.not-web-platform.test,www1.not-web-platform.test,www1.www1.web-platform.test,www2.xn--lve-6lad.web-platform.test,www1.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.not-web-platform.test,www2.www1.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.not-web-platform.test,xn--lve-6lad.www.web-platform.test,www.www.web-platform.test,www1.xn--lve-6lad.web-platform.test,xn--lve-6lad.www2.web-platform.test,www.www2.web-platform.test,www2.www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.not-web-platform.test,www1.www.web-platform.test,www.xn--lve-6lad.web-platform.test,www.www.not-web-platform.test,xn--lve-6lad.xn--lve-6lad.web-platform.test,xn--lve-6lad.www1.not-web-platform.test,www1.www1.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.www2.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www1.not-web-platform.test,www2.www2.web-platform.test,xn--lve-6lad.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--n8j6ds53lwwkrqhv28a.www.web-platform.test,xn--lve-6lad.not-web-platform.test,www2.xn--n8j6ds53lwwkrqhv28a.not-web-platform.test,www2.xn--lve-6lad.not-web-platform.test,xn--n8j6ds53lwwkrqhv28a.xn--lve-6lad.web-platform.test,www1.xn--lve-6lad.not-web-platform.test,www1.web-platform.test,www.www1.web-platform.test,www2.web-platform.test,www.xn--lve-6lad.not-web-platform.test,www.web-platform.test,xn--lve-6lad.xn--n8j6ds53lwwkrqhv28a.web-platform.test,www1.www2.not-web-platform.test,www2.www1.web-platform.test,www.www1.not-web-platform.test,www.xn--n8j6ds53lwwkrqhv28a.web-platform.test,xn--lve-6lad.www2.not-web-platform.test,www2.www.not-web-platform.test"}}}}}
14:31:31 INFO - PID 1292 | 1549722691402 mozrunner::runner INFO Running command: "Z:\\task_1549719941\\build\\application\\firefox\\firefox.exe" "-marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\task_1549719941\\AppData\\Local\\Temp\\rust_mozprofile.0cFIz7dJJeYp"
14:31:31 INFO - PID 1292 | 1549722691403 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828
14:31:31 INFO - PID 1292 | 1549722691882 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
14:31:31 INFO - PID 1292 | 1549722691882 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
14:31:31 INFO - PID 1292 | 1549722691883 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
14:31:32 INFO - PID 1292 | 1549722692048 Marionette TRACE Received observer notification profile-after-change
14:31:32 INFO - PID 1292 | 1549722692093 Marionette TRACE Received observer notification toplevel-window-ready
14:31:32 INFO - PID 1292 | 1549722692150 Marionette TRACE Received observer notification command-line-startup
14:31:32 INFO - PID 1292 | 1549722692150 Marionette TRACE Received observer notification nsPref:changed
14:31:32 INFO - PID 1292 | 1549722692150 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
14:31:32 INFO - PID 1292 | 1549722692288 Marionette TRACE Received observer notification toplevel-window-ready
14:31:33 INFO - PID 1292 | WARN: compileToBinary(235):
14:31:33 INFO - PID 1292 | C:\fakepath(203,14-129): warning X3571: pow(f, e) will not work for negative f, use abs(f) or conditionally handle negative values if you expect them
14:31:33 INFO - PID 1292 | C:\fakepath(209,58-112): warning X3571: pow(f, e) will not work for negative f, use abs(f) or conditionally handle negative values if you expect them
14:31:33 INFO - PID 1292 |
14:31:33 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/forward/user_prompts.py | expected OK
14:31:33 INFO - TEST-INFO took 185010ms

Blocks: 1525106
Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/<anything>.py | expected OK → Intermittent QuantumRender TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/<random>.py | expected OK

Responding to your question from bug 1525106:

The QR code doesn't touch the networking stack, although opening new windows is known to be slower, particularly on Linux where we haven't optimized it as much. So it's possible that's happening here, if the wdspec tests open and close a lot of windows. Or if you see the delay progressively increasing through the test run, it could be that we're leaking something regularly and the memory constraints are getting tighter and tighter causing things to get slower and slower.

It's actually not happening all the time. Only some of the commands show this strange very slow processing, and then causing those timeout errors.

Now that I consolidated all the different bugs into this one, lets wait until the next OF comment, so that we can see which platforms are affected, and how often it happens. Maybe be can find a way to reproduce locally, and to identify the problem.

The ccov builds should not be running. See the fixes from bug 1495002. I assume that the downstream sync from bug 1584612 might have reverted some logic which hasn't been correctly set before? James or David can you please have a look?

As such the recent comments and classifications do not apply to this bug.

Flags: needinfo?(james)
Flags: needinfo?(dheiberg)

I'm pretty sure the right metadata fix here is to make testing/web-platform/meta/webdriver/tests/new_session/timeouts.py.ini look like:

[timeouts.py]
  disabled:
    if ccov and (os == "win") and (bits == 64) and (version == "10.0.17134"): https://bugzilla.mozilla.org/show_bug.cgi?id=1495002
  expected:
    if (os == "linux") and not debug: ["OK", "TIMEOUT"]

That said I'm not sure why it's timing out on linux; that seems like it's worth an investigation. I suspect we maybe just need to add a long timeout pragma to the file.

Flags: needinfo?(james)
Flags: needinfo?(dheiberg)

This is still failing on win ccov, but on different file: webdriver/tests/permissions/set.py
The disable patch from Bug 1495002 was for webdriver/tests/new_session/timeouts.py

https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=windows%2C10%2Cx64%2Cccov%2Cdebug%2Cweb%2Cplatform%2Ctests%2Ctest-windows10-64-ccov%2Fdebug-web-platform-tests-wdspec-e10s-3%2Cw%28wd3%29&selectedJob=272490371

Since this bug is tracking "QuantumRender" failures and Bug 1524813 is a dupe of this bug, which would be the best option?

Flags: needinfo?(james)

I'm fairly sure all those logged failures are similar to bug 1495002, and that we should make the same meta adjustments as what we did on the other bug. Please feel free to update the summary of bug 1495002 to widen it up for more tests, or at least permissions.

Cristina, could you work on such a patch similar to what you did for the others? I'm happy to review it on that other mentioned bug. Thanks!

Flags: needinfo?(james)
Flags: needinfo?(hskupin)
Flags: needinfo?(ccoroiu)

Patch on bug 1495002.

Flags: needinfo?(ccoroiu)

(In reply to Intermittent Failures Robot from comment #49)

10 failures in 3030 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

All the recently classified failures are actually related to bug 1739186. Could someone please fix the classification? Thanks

Flags: needinfo?(sheriffs)

Thanks Sebastian! As such the last failures on this bug happened 5 months ago. As such lets close as WFM.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
Has Regression Range: --- → yes
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.