Closed Bug 1765787 Opened 3 years ago Closed 9 months ago

Intermittent layout/generic/test/test_bug514732-2.xhtml | single tracking bug

Categories

(Core :: Layout, defect, P3)

Product:
Core
Component:
Layout
Type:
defect

Tracking

()

Status:
RESOLVED FIXED

People

(Reporter: jmaher, Unassigned)

References

Details

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

Attachments

(1 file)

diagnostic patch to add some dump() logging to the test
1.45 KB, text/plain
Details
No description provided.
Severity: -- → S4

Update:
There have been 36 failures within the last 7 days:
• 6 failures on Linux 18.04 x64 WebRender opt
• 6 failures on Linux 18.04 x64 WebRender Shippable opt
• 8 failures on OS X 10.15 WebRender opt
• 11 failures on OS X 10.15 WebRender Shippable opt
• 4 failures on Windows 10 x64 2004 WebRender opt
• 1 failures on Windows 10 x64 2004 WebRender Shippable opt
Failure lines that were classified with this bug are: Test timed out and Unexpected event (MozScrolledAreaChanged) occurred
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=383878681&repo=autoland&lineNumber=128054

[task 2022-07-10T10:52:14.385Z] 10:52:14     INFO - TEST-START | layout/generic/test/test_bug514732-2.xhtml
[task 2022-07-10T10:52:14.452Z] 10:52:14     INFO - GECKO(1936) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2022-07-10T10:52:14.453Z] 10:52:14     INFO - GECKO(1936) | TEST: eventListener received a MozScrolledAreaChanged event for page , persisted=undefined
[task 2022-07-10T10:52:14.487Z] 10:52:14     INFO - GECKO(1936) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 0, persisted=undefined
[task 2022-07-10T10:52:14.488Z] 10:52:14     INFO - TEST-INFO | started process screencapture
[task 2022-07-10T10:52:14.611Z] 10:52:14     INFO - TEST-INFO | screencapture: exit 0
[task 2022-07-10T10:52:14.611Z] 10:52:14     INFO - Buffered messages logged at 10:52:14
[task 2022-07-10T10:52:14.611Z] 10:52:14     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2022-07-10T10:52:14.612Z] 10:52:14     INFO - Buffered messages finished
[task 2022-07-10T10:52:14.612Z] 10:52:14     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2022-07-10T10:52:14.612Z] 10:52:14     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:417:16
[task 2022-07-10T10:52:14.612Z] 10:52:14     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:492:7
[task 2022-07-10T10:52:14.614Z] 10:52:14     INFO - GECKO(1936) | TEST: removing event listeners
[task 2022-07-10T10:52:14.615Z] 10:52:14     INFO - GECKO(1936) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2022-07-10T10:52:14.622Z] 10:52:14     INFO - GECKO(1936) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2022-07-10T10:52:14.623Z] 10:52:14     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2022-07-10T10:52:14.657Z] 10:52:14     INFO - GECKO(1936) | TEST: removing event listeners
[task 2022-07-10T10:52:14.658Z] 10:52:14     INFO - GECKO(1936) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2022-07-10T10:52:14.658Z] 10:52:14     INFO - GECKO(1936) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 0, persisted=undefined
[task 2022-07-10T10:52:14.659Z] 10:52:14     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2022-07-10T10:52:14.798Z] 10:52:14     INFO - GECKO(1936) | TEST: removing event listeners
[task 2022-07-10T10:52:14.798Z] 10:52:14     INFO - GECKO(1936) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2022-07-10T10:52:14.799Z] 10:52:14     INFO - GECKO(1936) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2022-07-10T10:52:14.800Z] 10:52:14     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2022-07-10T10:52:14.924Z] 10:52:14     INFO - GECKO(1936) | TEST: removing event listeners
[task 2022-07-10T10:52:14.927Z] 10:52:14     INFO - must wait for focus
[task 2022-07-10T10:52:14.941Z] 10:52:14     INFO - GECKO(1936) | MEMORY STAT | vsize 15453MB | residentFast 306MB | heapAllocated 125MB
[task 2022-07-10T10:52:14.943Z] 10:52:14     INFO - TEST-OK | layout/generic/test/test_bug514732-2.xhtml | took 558ms
[task 2022-07-10T10:52:14.956Z] 10:52:14     INFO - TEST-START | layout/generic/test/test_bug632379.xhtml
Whiteboard: [retriggered] → [retriggered][stockwell needswork:owner]

Hi Daniel! Can you please take a look at this?
Thank you!

Flags: needinfo?(dholbert)

FWIW, before the "single tracking bug" merging...

(In reply to Iulian Moraru from comment #13)

Failure lines that were classified with this bug are: Test timed out

...this was originally bug 1756952.

and Unexpected event (MozScrolledAreaChanged) occurred

...this was originally bug 1603955.

Depends on: 1756952

This also doesn't seem to be a regression (or not a substantial one), though the "high-frequency weeks" have perhaps come up a bit more frequently.

It looks like this test has been failing in the "Unexpected event" mode at a low-to-medium level for quite a while. (See bug 1603955 in general, and specifically bug 1603955 comment 65 with 0.007 failures/push and e.g. bug 1603955 comment 108 through 111 with ~0.01 failures/push, which is about the frequency that it's failing right now in the most-failure-heavy weeks. Though there are still "low-frequency" weeks like e.g. comment 8 here with 0.002 failures/push.)

This eventually needs some dedicated investigation; this is likely some sort of race condition around events and navigation (the test involves an iframe which navigates and then listens for events, including the supposedly "unexpected" one here). I don't have cycles to do that at the moment but could do so at some point if this continues to be a problem. --> Leaving needinfo open for now but may not have much additional notes here soon.

There have been 35 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-32-2004-qr
  • windows10-32-2004-shippable-qr
  • windows10-64-2004-qr
  • windows10-64-2004-shippable-qr

There have been 35 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-32-2004-qr
  • windows10-32-2004-shippable-qr
  • windows10-64-2004-qr
  • windows10-64-2004-shippable-qr

There have been 30 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-32-2004-qr
  • windows10-64-2004-shippable-qr

There have been 39 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-ccov-qr
  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-32-2004-qr
  • windows10-32-2004-shippable-qr
  • windows10-64-2004-qr
  • windows10-64-2004-shippable-qr

I may have caught the "Test timed out" version of this bug, in rr (from just running the test locally).

I'm uploading the trace to pernosco and I'll post the pernosco link here when I've got it.

Flags: needinfo?(dholbert)

Pernosco link, at the moment where we determine the test timed out:
https://pernos.co/debug/9aCS98rQ7fsqUoevbd_NOw/index.html#f{m[HEiY,AA_,t[XA,Bx5O_,f{e[HEiW,AR1h_,s{af1iR5vAA,bFw,uPGP0,oPHYx___/

This was in a local test run with the test being run over and over. On the 75th iteration of the test, we have:

 7:30.86 TEST_START: layout/generic/test/test_bug514732-2.xhtml
[...]
 7:31.33 GECKO(466503) TEST: registering a listener for MozScrolledAreaChanged events
12:30.87 INFO Not taking screenshot here: see the one that was previously logged
12:30.87 FAIL Test timed out. -

I wrote a local patch (attached here) to add some dump()-style logging to the test to help make it a bit clearer when we're timing out, what the last thing that happened right before that is, etc.

I'll try to get another pernosco session with a test failure & with this logging included.

Here's a pernosco trace with the logging from the attached diagnostic patch:
https://pernos.co/debug/JdY09e5OM2_k_kq5D5rLiQ/index.html#f{m[FAoK,AA_,t[XA,CNS8__/

Here's the doomed test-run, from this pernosco trace:

 3:35.84 INFO SimpleTest START Loop 154
 3:35.84 TEST_START: layout/generic/test/test_bug514732-2.xhtml
 3:35.86 GECKO(578745) [Parent 578745, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /scratch/work/builds/mozilla-central/mozilla/chrome/nsChromeRegistry.cpp:180
 3:35.86 GECKO(578745) [Parent 578745, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /scratch/work/builds/mozilla-central/mozilla/dom/security/nsCSPService.cpp:190
 3:35.96 GECKO(578745) [Parent 578745, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /scratch/work/builds/mozilla-central/mozilla/xpcom/threads/IdleTaskRunner.cpp:198
 3:36.00 GECKO(578745) [Parent 578745, Main Thread] WARNING: NS_ENSURE_TRUE(inst) failed: file StaticComponents.cpp:9499
 3:36.01 GECKO(578745) [Parent 578745, Main Thread] WARNING: NS_ENSURE_TRUE(inst) failed: file StaticComponents.cpp:10144
 3:36.17 GECKO(578745) [Parent 578745, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /scratch/work/builds/mozilla-central/mozilla/xpcom/threads/IdleTaskRunner.cpp:198
 3:36.23 GECKO(578745) [Parent 578745, Main Thread] WARNING: '!CanHandleWith(aPresContext)', file /scratch/work/builds/mozilla-central/mozilla/dom/events/IMEStateManager.cpp:498
 3:36.25 GECKO(578745) In nextTest
 3:36.25 GECKO(578745) Entering testIterator
 3:36.25 GECKO(578745) In doPageNavigation for data URI:
 3:36.25 GECKO(578745) TEST: registering a listener for MozScrolledAreaChanged events
 3:36.25 GECKO(578745) TEST: eventListener received a MozScrolledAreaChanged event for page , persisted=undefined
 3:36.25 PASS A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred
 3:36.29 GECKO(578745) [2022-09-19T22:45:34Z WARN  webrender::renderer::init] asking to enable_gpu_markers but no supporting extension was found
 3:36.33 GECKO(578745) [2022-09-19T22:45:34Z WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
 3:36.33 GECKO(578745) [2022-09-19T22:45:34Z WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
 3:36.37 GECKO(578745) TEST: removing event listeners
 3:36.38 GECKO(578745) In nextTest
 3:36.38 GECKO(578745) In doPageNavigation for data URI:
 3:36.38 GECKO(578745) TEST: registering a listener for MozScrolledAreaChanged events
 3:36.39 GECKO(578745) [Parent 578745, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /scratch/work/builds/mozilla-central/mozilla/parser/html/nsHtml5StreamParser.cpp:1234
 3:36.40 GECKO(578745) TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
 3:36.39 PASS A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred
 3:36.41 GECKO(578745) [Parent 578745, Main Thread] WARNING: '!scrollbar', file /scratch/work/builds/mozilla-central/mozilla/widget/Theme.cpp:1071
 3:36.46 GECKO(578745) TEST: removing event listeners
 3:36.46 GECKO(578745) In nextTest
 3:36.47 GECKO(578745) In doPageNavigation back:
 3:36.47 GECKO(578745) TEST: registering a listener for MozScrolledAreaChanged events
 5:29.61 GECKO(578745) [2022-09-19T22:47:27Z WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
 7:29.70 GECKO(578745) 1663627767810	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
 8:35.86 INFO Failed to retrieve MOZ_UPLOAD_DIR env var
 8:35.85 FAIL Test timed out. - 


So: in this trace and one other similar one that I captured, the timeout seems to be during (or just after) the In doPageNavigation back step.

There have been 32 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-ccov-qr
  • linux1804-64-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-64-2004-qr
  • windows10-64-2004-shippable-qr

There have been 32 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-ccov-qr
  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
  • windows10-32-2004-qr
  • windows10-32-2004-shippable-qr
  • windows10-64-2004-qr
task 2022-12-23T16:24:12.429Z] 16:24:12     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2022-12-23T16:24:12.430Z] 16:24:12     INFO - Buffered messages finished
[task 2022-12-23T16:24:12.430Z] 16:24:12     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2022-12-23T16:24:12.430Z] 16:24:12     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:404:16
[task 2022-12-23T16:24:12.430Z] 16:24:12     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:489:7
[task 2022-12-23T16:24:12.431Z] 16:24:12     INFO - GECKO(1975) | [Parent 1975, Main Thread] WARNING: '!scrollbar', file /builds/worker/checkouts/gecko/widget/Theme.cpp:1105
[task 2022-12-23T16:24:12.431Z] 16:24:12     INFO - GECKO(1975) | TEST: removing event listeners
[task 2022-12-23T16:24:12.432Z] 16:24:12     INFO - GECKO(1975) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2022-12-23T16:24:12.432Z] 16:24:12     INFO - GECKO(1975) | [Parent 1975, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:1234
[task 2022-12-23T16:24:12.433Z] 16:24:12     INFO - GECKO(1975) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2022-12-23T16:24:12.433Z] 16:24:12     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred
Flags: needinfo?(dholbert)
Whiteboard: [retriggered][stockwell unknown] → [retriggered][stockwell needswork:owner]

There have been 39 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-ccov-qr
  • linux1804-64-qr
  • linux1804-64-shippable-qr
  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
[task 2023-01-20T01:50:04.052Z] 01:50:04     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2023-01-20T01:50:04.052Z] 01:50:04     INFO - Buffered messages finished
[task 2023-01-20T01:50:04.052Z] 01:50:04     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2023-01-20T01:50:04.052Z] 01:50:04     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:404:16
[task 2023-01-20T01:50:04.052Z] 01:50:04     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:489:7
[task 2023-01-20T01:50:04.053Z] 01:50:04     INFO - GECKO(6629) | TEST: removing event listeners
[task 2023-01-20T01:50:04.053Z] 01:50:04     INFO - GECKO(6629) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-01-20T01:50:04.309Z] 01:50:04     INFO - GECKO(6629) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2023-01-20T01:50:04.311Z] 01:50:04     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred

There have been 32 total failures in the last 7 days.
There are:

  • 1 failure on linux1804-64-ccov-qr
  • 5 failures on linux1804-64-qr
  • 2 failures on linux1804-64-shippable-qr
  • 10 failures on macosx1015-64-qr
  • 14 failures on macosx1015-64-shippable-qr

Recent failure log.

[task 2023-02-06T04:38:47.212Z] 04:38:47     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2023-02-06T04:38:47.212Z] 04:38:47     INFO - Buffered messages finished
[task 2023-02-06T04:38:47.213Z] 04:38:47     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2023-02-06T04:38:47.213Z] 04:38:47     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:404:16
[task 2023-02-06T04:38:47.213Z] 04:38:47     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:489:7
[task 2023-02-06T04:38:47.213Z] 04:38:47     INFO - GECKO(2874) | TEST: removing event listeners
[task 2023-02-06T04:38:47.214Z] 04:38:47     INFO - GECKO(2874) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-02-06T04:38:47.214Z] 04:38:47     INFO - GECKO(2874) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2023-02-06T04:38:47.215Z] 04:38:47     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred

Update

There have been 30 failures within the last 7 days:

  • 14 failures on OS X 10.15 WebRender Shippable opt
  • 9 failures on OS X 10.15 WebRender opt
  • 3 failures on Linux 18.04 x64 WebRender Shippable opt
  • 3 failures on Linux 18.04 x64 WebRender opt
  • 1 failure on Linux 18.04 x64 CCov WebRender opt

Two types of failures:

[task 2023-02-08T01:30:30.672Z] 01:30:30     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2023-02-08T01:30:30.672Z] 01:30:30     INFO - Buffered messages finished
[task 2023-02-08T01:30:30.673Z] 01:30:30     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2023-02-08T01:30:30.673Z] 01:30:30     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:404:16
[task 2023-02-08T01:30:30.673Z] 01:30:30     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:489:7
[task 2023-02-08T01:30:30.674Z] 01:30:30     INFO - GECKO(1776) | TEST: removing event listeners
[task 2023-02-08T01:30:30.674Z] 01:30:30     INFO - GECKO(1776) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-02-08T01:30:30.690Z] 01:30:30     INFO - GECKO(1776) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2023-02-08T01:30:30.691Z] 01:30:30     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 

[task 2023-02-09T03:05:53.488Z] 03:05:53     INFO - TEST-START | layout/generic/test/test_bug514732-2.xhtml
[task 2023-02-09T03:05:53.551Z] 03:05:53     INFO - GECKO(2126) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-02-09T03:05:53.551Z] 03:05:53     INFO - GECKO(2126) | TEST: eventListener received a MozScrolledAreaChanged event for page , persisted=undefined
[task 2023-02-09T03:05:53.582Z] 03:05:53     INFO - GECKO(2126) | TEST: removing event listeners
[task 2023-02-09T03:05:53.582Z] 03:05:53     INFO - GECKO(2126) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-02-09T03:05:53.585Z] 03:05:53     INFO - GECKO(2126) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 1, persisted=undefined
[task 2023-02-09T03:05:53.656Z] 03:05:53     INFO - GECKO(2126) | TEST: removing event listeners
[task 2023-02-09T03:05:53.656Z] 03:05:53     INFO - GECKO(2126) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2023-02-09T03:06:20.213Z] 03:06:20     INFO - GECKO(2126) | 2023-02-09 03:06:20.211 firefox[2126:31802] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
[task 2023-02-09T03:11:23.047Z] 03:11:23     INFO - TEST-INFO | started process screencapture
[task 2023-02-09T03:11:23.169Z] 03:11:23     INFO - TEST-INFO | screencapture: exit 0
[task 2023-02-09T03:11:23.169Z] 03:11:23     INFO - Buffered messages logged at 03:05:53
[task 2023-02-09T03:11:23.170Z] 03:11:23     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2023-02-09T03:11:23.170Z] 03:11:23     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2023-02-09T03:11:23.170Z] 03:11:23     INFO - Buffered messages finished
[task 2023-02-09T03:11:23.171Z] 03:11:23     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Test timed out. - 
[task 2023-02-09T03:11:24.176Z] 03:11:24     INFO - GECKO(2126) | MEMORY STAT | vsize 7858MB | residentFast 309MB | heapAllocated 116MB
[task 2023-02-09T03:11:24.177Z] 03:11:24     INFO - TEST-OK | layout/generic/test/test_bug514732-2.xhtml | took 330689ms
Flags: needinfo?(dholbert)

Daniel, can you help us assign this to someone?
Thank you.

Flags: needinfo?(dholbert)

Update

There have been 32 total failures within the last 7 days:

  • 1 failure on Linux 18.04 x64 WebRender opt
  • 2 failures on Linux 18.04 x64 WebRender Shippable opt
  • 10 failures on OS X 10.15 WebRender opt
  • 19 failures on OS X 10.15 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=444944107&repo=autoland&lineNumber=5989

[task 2024-01-28T15:21:51.241Z] 15:21:51     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred 
[task 2024-01-28T15:21:51.242Z] 15:21:51     INFO - Buffered messages finished
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug514732-2.xhtml | Unexpected event (MozScrolledAreaChanged) occurred 
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:426:16
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - pageEventListener@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:490:7
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - EventListener.handleEvent*doPageNavigation@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:245:31
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - testIterator@chrome://mochitests/content/chrome/layout/generic/test/file_bug514732_window.xhtml:43:25
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - nextTest@chrome://mochitests/content/chrome/layout/generic/test/file_bug514732_window.xhtml:28:13
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - doPageNavigation_complete@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:390:17
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - doPageNavigation/<@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:314:34
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - waitForTrue/<@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:630:20
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - setInterval handler*promiseTrue/condition<@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:647:18
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - promiseTrue@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:646:19
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - waitForTrue@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:629:14
[task 2024-01-28T15:21:51.244Z] 15:21:51     INFO - doPageNavigation@chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:309:16
[task 2024-01-28T15:21:51.245Z] 15:21:51     INFO - testIterator@chrome://mochitests/content/chrome/layout/generic/test/file_bug514732_window.xhtml:43:25
[task 2024-01-28T15:21:51.245Z] 15:21:51     INFO - nextTest@chrome://mochitests/content/chrome/layout/generic/test/file_bug514732_window.xhtml:28:13
[task 2024-01-28T15:21:51.245Z] 15:21:51     INFO - setTimeout handler*onload@chrome://mochitests/content/chrome/layout/generic/test/file_bug514732_window.xhtml:1:11
[task 2024-01-28T15:21:51.245Z] 15:21:51     INFO - GECKO(1785) | TEST: removing event listeners
[task 2024-01-28T15:21:51.246Z] 15:21:51     INFO - GECKO(1785) | TEST: registering a listener for MozScrolledAreaChanged events
[task 2024-01-28T15:21:51.246Z] 15:21:51     INFO - GECKO(1785) | TEST: eventListener received a MozScrolledAreaChanged event for page bug 514732 bfcache test page 0, persisted=undefined
[task 2024-01-28T15:21:51.247Z] 15:21:51     INFO - TEST-PASS | layout/generic/test/test_bug514732-2.xhtml | A MozScrolledAreaChanged event was expected, but a MozScrolledAreaChanged event occurred
Flags: needinfo?(dholbert)

Hi Daniel, can you help us assign this to someone?
Thank you.

Flags: needinfo?(dholbert)
Whiteboard: [retriggered][stockwell unknown] → [retriggered][stockwell needswork:owner]

Yeah, I'm taking a look; hopefully I should have more to share here within a day or so.

Depends on: 1878346

I just triggered lando for a patch in bug 1878346 which I think fixes the failures here. (Small patch, but required some nontrivial rr/pernosco investigation to figure out what was supposed to happen and what was actually happening.)

Flags: needinfo?(dholbert)

(I'd suggest that we leave this bug open for at least a few days to watch for additional reports, so we can be sure bug 1878346's patch really fixes things here.)

Actually I got pretty good confirmation on try that this is fixed; see bug 1878346 comment 6. So I think we're safe to close this as FIXED by bug 1878346 as soon as its patch hits central.

Status: NEW → RESOLVED
Closed: 9 months ago
Resolution: --- → FIXED

The recent intermittent failures on ESR should stop now; see bug 1878346 comment 14 through 17.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: