Closed Bug 1669007 Opened 2 months ago Closed 1 month ago

Intermittent layout/generic/test/test_scroll_position_restore.html | undefined assertion name - got 54560, expected 348260

Categories

(Core :: Layout, defect, P5)

defect

Tracking

()

RESOLVED FIXED
84 Branch
Tracking Status
firefox84 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: ccoroiu, NeedInfo)

References

(Regression)

Details

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

Attachments

(2 files)

Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=317469379&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aHhGdrn-TqS-TTdgX3qVgQ/runs/0/artifacts/public/logs/live_backing.log


[task 2020-10-03T10:06:52.944Z] 10:06:52     INFO - TEST-START | layout/generic/test/test_scroll_position_restore.html
[task 2020-10-03T10:06:52.949Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:52.949Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:52.949Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:52.974Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:52.974Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:52.974Z] 10:06:52     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:53.036Z] 10:06:53     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:53.036Z] 10:06:53     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:06:53.036Z] 10:06:53     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.634Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.634Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.635Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.653Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.653Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.653Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.672Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.672Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.672Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.683Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.683Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.684Z] 10:07:18     INFO - GECKO(1116) | [GPU 9040, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-10-03T10:07:18.702Z] 10:07:18     INFO - TEST-INFO | started process screenshot
[task 2020-10-03T10:07:18.782Z] 10:07:18     INFO - TEST-INFO | screenshot: exit 0
[task 2020-10-03T10:07:18.782Z] 10:07:18     INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_scroll_position_restore.html | undefined assertion name - got 54560, expected 348260```

This seems pretty frequent, if we did some retriggers of past pushes it should be possible to find the commit that regressed this.

I did a bunch of try pushes, from those it's pretty clear that this is caused by bug 1665196.

Regressed by: 1665196

There are 47 total failures in the last 7 days on windows10-64 debug, windows10-64-qr debug, windows7-32 debug

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=318926946&repo=autoland&lineNumber=28645

[task 2020-10-17T16:35:00.296Z] 16:35:00 INFO - TEST-START | layout/generic/test/test_scroll_position_restore.html
[task 2020-10-17T16:35:05.913Z] 16:35:05 INFO - GECKO(6552) | [Child 8188, Main Thread] WARNING: flushing shaped-word cache: file /builds/worker/checkouts/gecko/gfx/thebes/gfxFont.cpp:2742
[task 2020-10-17T16:35:15.358Z] 16:35:15 INFO - GECKO(6552) | [Child 8188, Main Thread] WARNING: flushing shaped-word cache: file /builds/worker/checkouts/gecko/gfx/thebes/gfxFont.cpp:2742
[task 2020-10-17T16:35:16.828Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:16.828Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:16.829Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:16.829Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:16.834Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:16.834Z] 16:35:16 INFO - GECKO(6552) | [Child 4480, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8492
[task 2020-10-17T16:35:17.034Z] 16:35:17 INFO - GECKO(6552) | [Child 8188, Main Thread] WARNING: flushing shaped-word cache: file /builds/worker/checkouts/gecko/gfx/thebes/gfxFont.cpp:2742
[task 2020-10-17T16:35:22.658Z] 16:35:22 INFO - GECKO(6552) | [Child 8188, Main Thread] WARNING: flushing shaped-word cache: file /builds/worker/checkouts/gecko/gfx/thebes/gfxFont.cpp:2742
[task 2020-10-17T16:35:24.763Z] 16:35:24 INFO - TEST-INFO | started process screenshot
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - TEST-INFO | screenshot: exit 0
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - TEST-UNEXPECTED-FAIL | layout/generic/test/test_scroll_position_restore.html | undefined assertion name - got 306240, expected 348260
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - handleLoad/<@layout/generic/test/test_scroll_position_restore.html:32:9
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - waitForPaints@SimpleTest/paint_listener.js:90:14
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - window.waitForAllPaintsFlushed@SimpleTest/paint_listener.js:94:18
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - handleLoad@layout/generic/test/test_scroll_position_restore.html:30:14
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - onload@layout/generic/test/file_scroll_position_restore.html:1:15
[task 2020-10-17T16:35:24.825Z] 16:35:24 INFO - GECKO(6552) | MEMORY STAT | vsize 2104338MB | vsizeMaxContiguous 71147857MB | residentFast 320MB | heapAllocated 164MB
[task 2020-10-17T16:35:25.977Z] 16:35:25 INFO - GECKO(6552) | [Parent 6200, Main Thread] WARNING: '!aObserver', file /builds/worker/checkouts/gecko/xpcom/ds/nsObserverService.cpp:236
[task 2020-10-17T16:35:25.982Z] 16:35:25 INFO - GECKO(6552) | [NPAPI 2132, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-10-17T16:35:25.992Z] 16:35:25 INFO - TEST-OK | layout/generic/test/test_scroll_position_restore.html | took 25698ms

Jonathan can you please take a look?

Flags: needinfo?(jfkthame)
Whiteboard: [stockwell needswork:owner]
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][retriggered]
Assignee: nobody → ccoroiu
Status: NEW → ASSIGNED

The regressing bug adds a pref (gfx.font_loader.delay=0) to one mochitests.ini for one dir of tests so that the timing of the font loading doesn't mess up some tests in that dir presumably. I want to try adding that pref for this test dir because I would prefer to keep this test enabled as this code is tricky and we do touch it decently often and it's hard to get right (easy to regress it) so I want to keep it enabled everywhere possible.

Pushed by tnikkel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a4853e82ea7a
Set the pref gfx.font_loader.delay=0 when running reftests in layout/general/test to fix test_scroll_position_restore.html intermittent failure.  r=jfkthame
Attachment #9183620 - Attachment is obsolete: true

Timothy, thank you for the patch! I'll mark as obsolete the disable patch.

Status: ASSIGNED → RESOLVED
Closed: 1 month ago
Resolution: --- → FIXED
Target Milestone: --- → 84 Branch
Attachment #9183620 - Attachment is obsolete: false
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered]
You need to log in before you can comment on or make changes to this bug.