Closed Bug 1819847 Opened 2 years ago Closed 1 year ago

Intermittent TCw TEST-UNEXPECTED-TIMEOUT | /css/css-tables/abspos-container-change-dynamic-001.html | single tracking bug

Categories

(Core :: Layout, defect, P5)

Product:
Core
Component:
Layout
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE
Tracking Flags:
Tracking Status
firefox-esr102 --- unaffected
firefox110 --- unaffected
firefox111 --- unaffected
firefox112 --- wontfix
firefox113 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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

[task 2023-03-02T08:01:55.783Z] 08:01:55     INFO - TEST-START | /css/css-tables/abspos-container-change-dynamic-001.html
[task 2023-03-02T08:01:55.791Z] 08:01:55     INFO - Setting pref dom.animations-api.compositing.enabled to true
[task 2023-03-02T08:01:55.820Z] 08:01:55     INFO - Setting pref layout.css.cascade-layers.enabled to true
[task 2023-03-02T08:01:55.835Z] 08:01:55     INFO - Setting pref layout.css.more_color_4.enabled to true
[task 2023-03-02T08:01:55.842Z] 08:01:55     INFO - PID 6340 | [CodeCoverage] Requested flush for 7928.
[task 2023-03-02T08:01:59.947Z] 08:01:59     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:00.180Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:00.182Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] Requested flush for 8628.
[task 2023-03-02T08:02:00.183Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] Requested flush for 3084.
[task 2023-03-02T08:02:00.184Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] Requested flush for 5868.
[task 2023-03-02T08:02:00.185Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] Requested flush for 6796.
[task 2023-03-02T08:02:00.186Z] 08:02:00     INFO - PID 6340 | [CodeCoverage] Requested flush for 6836.
[task 2023-03-02T08:02:14.813Z] 08:02:14     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:14.831Z] 08:02:14     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:15.590Z] 08:02:15     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:15.597Z] 08:02:15     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:16.792Z] 08:02:16     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:16.800Z] 08:02:16     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:17.681Z] 08:02:17     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:17.692Z] 08:02:17     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:18.388Z] 08:02:18     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:18.391Z] 08:02:18     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:19.532Z] 08:02:19     INFO - PID 6340 | 1677744139532	Marionette	INFO	Testing http://web-platform.test:8000/css/css-tables/abspos-container-change-dynamic-001.html == http://web-platform.test:8000/css/css-tables/abspos-container-change-dynamic-001-ref.html
[task 2023-03-02T08:02:19.779Z] 08:02:19     INFO - PID 6340 | 1677744139790	Marionette	INFO	No differences allowed
[task 2023-03-02T08:02:19.816Z] 08:02:19     INFO - PID 6340 | [CodeCoverage] Requested flush for 7928.
[task 2023-03-02T08:02:23.681Z] 08:02:23     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:23.994Z] 08:02:23     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:23.994Z] 08:02:23     INFO - PID 6340 | [CodeCoverage] Requested flush for 8628.
[task 2023-03-02T08:02:23.994Z] 08:02:23     INFO - PID 6340 | [CodeCoverage] Requested flush for 6836.
[task 2023-03-02T08:02:23.994Z] 08:02:23     INFO - PID 6340 | [CodeCoverage] Requested flush for 6796.
[task 2023-03-02T08:02:24.002Z] 08:02:24     INFO - PID 6340 | [CodeCoverage] Requested flush for 5868.
[task 2023-03-02T08:02:30.795Z] 08:02:30     INFO - Got timeout in harness
[task 2023-03-02T08:02:30.798Z] 08:02:30     INFO - TEST-UNEXPECTED-TIMEOUT | /css/css-tables/abspos-container-change-dynamic-001.html | TestRunner hit external timeout (this may indicate a hang)
[task 2023-03-02T08:02:30.798Z] 08:02:30     INFO - TEST-INFO took 35014ms
[task 2023-03-02T08:02:30.798Z] 08:02:30     INFO - No more tests
[task 2023-03-02T08:02:38.833Z] 08:02:38     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:38.838Z] 08:02:38     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:39.673Z] 08:02:39     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:39.683Z] 08:02:39     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:40.308Z] 08:02:40     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:40.317Z] 08:02:40     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:41.022Z] 08:02:41     INFO - PID 6340 | [CodeCoverage] flush completed.
[task 2023-03-02T08:02:41.025Z] 08:02:41     INFO - PID 6340 | [CodeCoverage] JS flush completed.
[task 2023-03-02T08:02:41.108Z] 08:02:41     INFO - PID 6340 | JavaScript error: chrome://remote/content/shared/TabManager.sys.mjs, line 106: TypeError: can't access property "gBrowser", win is null
[task 2023-03-02T08:02:41.127Z] 08:02:41     INFO - PID 6340 | 1677744161130	Marionette	INFO	Stopped listening on port 49871
[task 2023-03-02T08:02:41.464Z] 08:02:41     INFO - PID 6340 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 |           Blocker:  Waiting for ping task
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 |           State: (none)
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-02T08:02:41.466Z] 08:02:41     INFO - PID 6340 | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-02T08:02:41.474Z] 08:02:41     INFO - PID 6340 | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-02T08:02:41.474Z] 08:02:41     INFO - PID 6340 | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-02T08:02:41.474Z] 08:02:41     INFO - PID 6340 | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-02T08:02:41.476Z] 08:02:41     INFO - PID 6340 | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-02T08:02:41.476Z] 08:02:41     INFO - PID 6340 | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-02T08:02:41.476Z] 08:02:41     INFO - PID 6340 | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-02T08:02:41.476Z] 08:02:41     INFO - PID 6340 | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-02T08:02:41.497Z] 08:02:41     INFO - PID 6340 | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-02T08:02:41.497Z] 08:02:41     INFO - PID 6340 |           Blocker:  Waiting for ping task
[task 2023-03-02T08:02:41.497Z] 08:02:41     INFO - PID 6340 |           Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-02T08:02:41.497Z] 08:02:41     INFO - PID 6340 |           State: (none)
<...>
[task 2023-03-02T08:02:41.537Z] 08:02:41     INFO - PID 6340 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-02T08:02:41.539Z] 08:02:41     INFO - PID 6340 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-02T08:02:42.011Z] 08:02:42     INFO - PID 6340 | [Child 6836, IPC I/O Child] WARNING: pipe error: 232: file Z:/task_167773419485767/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc:583
[task 2023-03-02T08:02:43.408Z] 08:02:43     INFO - PID 6340 | [Parent 7928, IPC I/O Parent] WARNING: Process 5868 may be hanging at shutdown; will wait for up to 80000ms: file Z:/task_167773419485767/build/src/ipc/chromium/src/chrome/common/process_watcher_win.cc:129
[task 2023-03-02T08:02:48.501Z] 08:02:48     INFO - PID 6340 | [Parent 7928, IPC I/O Parent] WARNING: Process 6836 may be hanging at shutdown; will wait for up to 74906ms: file Z:/task_167773419485767/build/src/ipc/chromium/src/chrome/common/process_watcher_win.cc:129
[task 2023-03-02T08:03:02.945Z] 08:03:02     INFO - Browser exited with return code 0
[task 2023-03-02T08:03:02.949Z] 08:03:02  WARNING - Command left in command_queue during cleanup: 'test_ended', (<wptrunner.wpttest.ReftestTest /css/css-tables/abspos-container-change-dynamic-001.html>, (<wptrunner.wpttest.ReftestResult PASS>, []))
[task 2023-03-02T08:03:02.949Z] 08:03:02     INFO - Closing logging queue
[task 2023-03-02T08:03:02.950Z] 08:03:02     INFO - queue closed
[task 2023-03-02T08:03:02.992Z] 08:03:02     INFO - SUITE-END | took 73s
[task 2023-03-02T08:03:02.993Z] 08:03:02     INFO - Got 1 unexpected results, with 0 unexpected passes

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

:emilio, since you are the author of the regressor, bug 1815552, could you take a look?

For more information, please visit auto_nag documentation.

status-firefox110: --- → unaffected
status-firefox111: --- → unaffected
status-firefox112: --- → affected
status-firefox-esr102: --- → unaffected
Flags: needinfo?(emilio)

ccov builds being slow perhaps? Doesn't seem worth digging into tbh.

Flags: needinfo?(emilio)

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

status-firefox113: --- → affected

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 1 year ago
status-firefox112: affected → wontfix
status-firefox113: affected → wontfix
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.