Closed Bug 1724361 Opened 4 months ago Closed 4 months ago

Intermittent [tier 2] /resize-observer/observe.html | test10: simple border-box observation - assert_unreached: Timed out waiting for notification. (100ms) Reached unreachable code

Categories

(Core :: Layout, defect, P5)

defect

Tracking

()

RESOLVED FIXED
93 Branch
Tracking Status
firefox-esr78 --- unaffected
firefox-esr91 --- unaffected
firefox90 --- unaffected
firefox91 --- unaffected
firefox92 --- wontfix
firefox93 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(3 files)

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=347609173&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Ab-UMhPrR7-0r5UEn5jj4A/runs/0/artifacts/public/logs/live_backing.log


[task 2021-08-06T06:23:13.568Z] 06:23:13     INFO - TEST-START | /paint-timing/with-first-paint/first-contentful-paint.html
[task 2021-08-06T06:23:13.570Z] 06:23:13     INFO - Closing window 0c7bd111-ee42-4454-9420-7c5acd9e57e5
[task 2021-08-06T06:23:13.675Z] 06:23:13     INFO - 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test0: simple observation 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test1: multiple observation on same element trigger only one 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test2: throw exception when observing non-element 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test3: disconnect stops all notifications 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test4: unobserve target stops notifications, unobserve non-observed does nothing 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test5: observe img 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test6: iframe notifications 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test7: callback.this 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test8: simple content-box observation 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-PASS | /resize-observer/observe.html | test9: simple content-box observation but keep border-box size unchanged 
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - TEST-UNEXPECTED-FAIL | /resize-observer/observe.html | test10: simple border-box observation - assert_unreached: Timed out waiting for notification. (100ms) Reached unreachable code
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - _handleTimeout/</<@http://web-platform.test:8000/resize-observer/resources/resizeTestHelper.js:108:27
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - _handleTimeout/<@http://web-platform.test:8000/resize-observer/resources/resizeTestHelper.js:107:27
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-06T06:23:13.676Z] 06:23:13     INFO - _handleTimeout@http://web-platform.test:8000/resize-observer/resources/resizeTestHelper.js:102:23
[task 2021-08-06T06:23:13.677Z] 06:23:13     INFO - Test.prototype.step_timeout/<@http://web-platform.test:8000/resources/testharness.js:2148:22
[task 2021-08-06T06:23:13.677Z] 06:23:13     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-06T06:23:13.677Z] 06:23:13     INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:2114:35
[task 2021-08-06T06:23:13.677Z] 06:23:13     INFO - TEST-TIMEOUT | /resize-observer/observe.html | took 2601ms
[task 2021-08-06T06:23:13.679Z] 06:23:13     INFO - PID 6072 | 1628230993672	Marionette	INFO	Stopped listening on port 56115
[task 2021-08-06T06:23:13.723Z] 06:23:13     INFO - PID 6072 | JavaScript error: resource:///modules/Interactions.jsm, line 230: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
[task 2021-08-06T06:23:14.108Z] 06:23:14     INFO - Browser exited with return code 0
[task 2021-08-06T06:23:14.111Z] 06:23:14     INFO - Closing logging queue
[task 2021-08-06T06:23:14.111Z] 06:23:14     INFO - queue closed
[task 2021-08-06T06:23:14.161Z] 06:23:14     INFO - Application command: Z:\task_162822734393195\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_162822734393195\AppData\Local\Temp\tmpzzpvlbdb
[task 2021-08-06T06:23:14.175Z] 06:23:14     INFO - Starting runner
[task 2021-08-06T06:23:14.565Z] 06:23:14     INFO - PID 760 | 1628230994564	Marionette	INFO	Marionette enabled
[task 2021-08-06T06:23:15.983Z] 06:23:15     INFO - PID 760 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_162822734393195\\AppData\\Local\\Temp\\tmpzzpvlbdb\\search.json.mozlz4", (void 0)))
[task 2021-08-06T06:23:16.146Z] 06:23:16     INFO - .
[task 2021-08-06T06:23:16.146Z] 06:23:16     INFO - TEST-TIMEOUT | /paint-timing/with-first-paint/first-contentful-paint.html | took 2587ms
Flags: needinfo?(michelle)

Will wait to see how frequent this will get (per advise from :jmaher).

Flags: needinfo?(michelle)

Boris, I think you're looking at resize-observer stuff recently -- maybe you could take a look and see if you can figure out what's going on here?

Flags: needinfo?(boris.chiou)

Also: emilio notes that the test has
assert_unreached: Timed out waiting for notification. (100ms) Reached unreachable code

It's possible that 100ms might be too low - that's pretty small. Maybe there are some conditions where the event in question takes a bit longer, and the test needs to be changed to poll for a bit longer or something? (i.e. might be a test bug rather than a real bug)

Also: I'm not sure what the 2004 means in windows10-64-2004-shippable-qr. Is this Ubuntu 20.04 running on Windows 10 or something? (I see that this tagged [tier2], so I'm guessing this is some sort of weird configuration like that...) [EDIT: Ah, this is a particular release of windows 10: https://docs.microsoft.com/en-us/windows/whats-new/whats-new-windows-10-version-2004 ]

(In reply to Daniel Holbert [:dholbert] from comment #6)

Also: emilio notes that the test has
assert_unreached: Timed out waiting for notification. (100ms) Reached unreachable code

It's possible that 100ms might be too low - that's pretty small. Maybe there are some conditions where the event in question takes a bit longer

The 100ms comes from this line specifically:
https://searchfox.org/mozilla-central/rev/d3683dbb252506400c71256ef3994cdbdfb71ada/testing/web-platform/tests/resize-observer/resources/resizeTestHelper.js#55

It looks like we use that timeout for many of the parts of this test, for what it's worth. (So it's somewhat interesting if it does only get tripped for this one particular subtest.)

The probability is not high now so it's a little bit hard to check if increasing the timeout time works on try. However, we can push a patch that increases the timeout from 100ms to 200ms and wait for a couple of days. It seems like we have had many intermittents recently on different subtests. Hope tweaking the timeout can reduce the probability in these subtests.

We got some intermittents because of timeout in test5, test9, test10,
test14, test15 in some platforms, so this patch add an extra parameter to
ResizeTestHelper to tweak the timeout duration. The default value is still
100ms, and we tweak it to 200ms for test10. Let's see if it helps in Gecko.

We tweak these subtests first based on the current intermittent bugs in
bugzilla by querying "resize-observer/observe.html".

Attachment #9236509 - Attachment description: Bug 1724361 - Increase timeout for some subtest in observe.html to reduce the intermittents. → Bug 1724361 - Try to increase timeout time for some subtests to reduce the probability of intermittents.
Attachment #9236509 - Attachment description: Bug 1724361 - Try to increase timeout time for some subtests to reduce the probability of intermittents. → Bug 1724361 - Try to increase timeout value to reduce the probability of intermittents for ResizeTestHelper.

test6() has side effects if we got fail from iframe. We have to move
ResolvePromise() before the assert_equals() because if this assert fails, it
interrupts this async test. In this case, no one resolve the promise.
So we have to resolve the promise before any asserts.

Besides, move the event listener above the iframe src setup.

Add a dummy test if the decoding of the image fails, and move the
ResizeTestHelper (which creates an async_test) before it starts.

Assignee: nobody → boris.chiou
Status: NEW → ASSIGNED
Flags: needinfo?(boris.chiou)
Pushed by bchiou@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/8b5050f0ea95
Reduce the side effect of iframe test in observe.html. r=hiro
https://hg.mozilla.org/integration/autoland/rev/63749e4d2613
Fix a JS error because we use the assert outside the test callbacks. r=emilio
https://hg.mozilla.org/integration/autoland/rev/f62cad8b2ebd
Try to increase timeout value to reduce the probability of intermittents for ResizeTestHelper. r=emilio
Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/30062 for changes under testing/web-platform/tests
Status: ASSIGNED → RESOLVED
Closed: 4 months ago
Resolution: --- → FIXED
Target Milestone: --- → 93 Branch
Upstream PR merged by moz-wptsync-bot
Duplicate of this bug: 1725051
Duplicate of this bug: 1723619
Duplicate of this bug: 1724574
Duplicate of this bug: 1724826
Duplicate of this bug: 1725370
You need to log in before you can comment on or make changes to this bug.