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

Status: RESOLVED FIXED

(Core :: Layout, defect, P5)

Description

[Treeherder Bug Filer]

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

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1718326

Comment 2

[Michelle Goossens [:masterwayz]]

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

Comment 3

[Intermittent Failures Robot]

1 failures in 2829 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1724361&startday=2021-08-02&endday=2021-08-08&tree=all

Comment 4

[Intermittent Failures Robot]

3 failures in 3025 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 3

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1724361&startday=2021-08-09&endday=2021-08-15&tree=all

Comment 5

[Daniel Holbert [:dholbert]]

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?

Comment 6

[Daniel Holbert [:dholbert]]

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 ]

Comment 7

[Daniel Holbert [:dholbert]]

(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.)

Comment 8

[Boris Chiou [:boris]]

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.

Comment 9

[Boris Chiou [:boris]]

Attachment: Bug 1724361 - Try to increase timeout value to reduce the probability of intermittents for ResizeTestHelper.

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".

Comment 10

[Boris Chiou [:boris]]

Attachment: Bug 1724361 - Reduce the side effect of iframe test in observe.html.

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.

Comment 11

[Boris Chiou [:boris]]

Attachment: Bug 1724361 - Fix a JS error because we use the assert outside the test callbacks.

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

Comment 12

[Pulsebot]

Pushed by [e-mail]:
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

Comment 13

[Web Platform Test Sync Bot (Matrix: #interop:mozilla.org)]

Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/30062 for changes under testing/web-platform/tests

Comment 14

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/8b5050f0ea95
https://hg.mozilla.org/mozilla-central/rev/63749e4d2613
https://hg.mozilla.org/mozilla-central/rev/f62cad8b2ebd

Comment 15

[Web Platform Test Sync Bot (Matrix: #interop:mozilla.org)]

Upstream PR merged by moz-wptsync-bot