Intermittent TV TinderboxPrint: Per-test run of ...\test_group_mouseevents.html<br/>: FAILURE
Categories
(Core :: Panning and Zooming, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr102 | --- | unaffected |
firefox114 | --- | unaffected |
firefox115 | --- | unaffected |
firefox116 | --- | affected |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, test-verify-fail)
Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=418694919&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aOy_bUKqQp2cU0AH_2h8xQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aOy_bUKqQp2cU0AH_2h8xQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
[task 2023-06-09T07:30:43.835Z] 07:30:43 INFO - TEST-START | gfx/layers/apz/test/mochitest/test_group_mouseevents.html
[task 2023-06-09T07:30:45.713Z] 07:30:45 INFO - GECKO(9152) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2023-06-09T07:30:45.724Z] 07:30:45 INFO - GECKO(9152) | WaitUntilApzStable: APZ flush done in parent proc
[task 2023-06-09T07:30:45.726Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | WaitUntilApzStable: got apz-flush-done in child proc
[task 2023-06-09T07:30:45.728Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | WaitUntilApzStable: done promiseFocus
[task 2023-06-09T07:30:45.730Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | WaitUntilApzStable: done promiseAllPaintsDone
[task 2023-06-09T07:30:45.732Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2023-06-09T07:30:45.732Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | PromiseApzRepaintsFlushed: APZ flush done
[task 2023-06-09T07:30:45.734Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | WaitUntilApzStable: all done
[task 2023-06-09T07:30:45.760Z] 07:30:45 INFO - GECKO(9152) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-09T07:30:45.791Z] 07:30:45 INFO - GECKO(9152) | helper_click.html?dtc=false | Finished synthesizing click, waiting for button to be clicked...
[task 2023-06-09T07:30:45.917Z] 07:30:45 INFO - GECKO(9152) | [Child 6720, Main Thread] WARNING: IPC message 'PWindowGlobal::Msg_UpdateBFCacheStatus' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:507
[task 2023-06-09T07:30:46.136Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2023-06-09T07:30:46.145Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: APZ flush done in parent proc
[task 2023-06-09T07:30:46.147Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | WaitUntilApzStable: got apz-flush-done in child proc
[task 2023-06-09T07:30:46.149Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | WaitUntilApzStable: done promiseFocus
[task 2023-06-09T07:30:46.150Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | WaitUntilApzStable: done promiseAllPaintsDone
[task 2023-06-09T07:30:46.152Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2023-06-09T07:30:46.157Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | PromiseApzRepaintsFlushed: APZ flush done
[task 2023-06-09T07:30:46.159Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | WaitUntilApzStable: all done
[task 2023-06-09T07:30:46.165Z] 07:30:46 INFO - GECKO(9152) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-09T07:30:46.199Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2023-06-09T07:30:46.208Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | PromiseApzRepaintsFlushed: APZ flush done
[task 2023-06-09T07:30:46.219Z] 07:30:46 INFO - GECKO(9152) | helper_click.html?dtc=true | Finished synthesizing click, waiting for button to be clicked...
[task 2023-06-09T07:30:46.324Z] 07:30:46 INFO - GECKO(9152) | [Child 6720, Main Thread] WARNING: IPC message 'PWindowGlobal::Msg_UpdateBFCacheStatus' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:507
[task 2023-06-09T07:30:46.560Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2023-06-09T07:30:46.560Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: APZ flush done in parent proc
[task 2023-06-09T07:30:46.562Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | WaitUntilApzStable: got apz-flush-done in child proc
[task 2023-06-09T07:30:46.570Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | WaitUntilApzStable: done promiseFocus
[task 2023-06-09T07:30:46.571Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | WaitUntilApzStable: done promiseAllPaintsDone
[task 2023-06-09T07:30:46.573Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2023-06-09T07:30:46.588Z] 07:30:46 INFO - GECKO(9152) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-09T07:30:46.594Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | PromiseApzRepaintsFlushed: APZ flush done
[task 2023-06-09T07:30:46.600Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | WaitUntilApzStable: all done
[task 2023-06-09T07:30:46.622Z] 07:30:46 INFO - GECKO(9152) | helper_drag_click.html | Finished synthesizing click with a drag in the middle
[task 2023-06-09T07:30:46.982Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: flushed APZ repaints in parent proc, waiting for callback...
[task 2023-06-09T07:30:46.987Z] 07:30:46 INFO - GECKO(9152) | WaitUntilApzStable: APZ flush done in parent proc
[task 2023-06-09T07:30:46.988Z] 07:30:46 INFO - GECKO(9152) | helper_drag_root_scrollbar.html | WaitUntilApzStable: got apz-flush-done in child proc
<...>
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - SUITE-START | Running 1 tests
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - :::
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: Test verification summary for:
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - :::
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: gfx/layers/apz/test/mochitest/test_group_mouseevents.html
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - :::
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: 1. Run each test 10 times in one browser. : FAIL
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: 2. Run each test 5 times in a new browser each time. : not run / incomplete
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: 3. Run each test 10 times in one browser, in chaos mode. : not run / incomplete
[task 2023-06-09T07:31:00.860Z] 07:31:00 INFO - ::: 4. Run each test 5 times in a new browser each time, in chaos mode. : not run / incomplete
[task 2023-06-09T07:31:00.864Z] 07:31:00 INFO - :::
[task 2023-06-09T07:31:00.865Z] 07:31:00 INFO - ::: Test verification FAILED!
[task 2023-06-09T07:31:00.865Z] 07:31:00 INFO - :::
[task 2023-06-09T07:31:00.866Z] 07:31:00 INFO - Buffered messages finished
[task 2023-06-09T07:31:00.866Z] 07:31:00 INFO - SUITE-END | took 0s
[task 2023-06-09T07:31:00.903Z] 07:31:00 INFO - Return code: 0
[task 2023-06-09T07:31:00.904Z] 07:31:00 ERROR - No checks run.
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - TinderboxPrint: mochitest-mochitest-plain<br/>23/0/0
[task 2023-06-09T07:31:00.904Z] 07:31:00 WARNING - setting return code to 2
[task 2023-06-09T07:31:00.904Z] 07:31:00 ERROR - TinderboxPrint: Per-test run of ...\test_group_mouseevents.html<br/>: FAILURE
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Per-test suites: {}
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Per-test suites: {}
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Running post-action listener: _package_coverage_data
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Running post-action listener: _resource_record_post_action
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Running post-action listener: process_java_coverage_data
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - [mozharness: 2023-06-09 07:31:00.904855Z] Finished run-tests step (success)
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - [mozharness: 2023-06-09 07:31:00.904855Z] Running uninstall step.
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Running pre-action listener: _resource_record_pre_action
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Running main action method: uninstall
[task 2023-06-09T07:31:00.904Z] 07:31:00 INFO - Skipping uninstall for non-MSIX test
[task 2023-06-09T07:31:00.905Z] 07:31:00 INFO - Running post-action listener: _resource_record_post_action
[task 2023-06-09T07:31:00.905Z] 07:31:00 INFO - [mozharness: 2023-06-09 07:31:00.905390Z] Finished uninstall step (success)
[task 2023-06-09T07:31:00.905Z] 07:31:00 INFO - Running post-run listener: _resource_record_post_run
[task 2023-06-09T07:31:02.218Z] 07:31:02 INFO - instance_metadata.json not found; unable to determine instance type
[task 2023-06-09T07:31:02.237Z] 07:31:02 INFO - Validating Perfherder data against Z:\task_168629067869068\mozharness\external_tools\performance-artifact-schema.json
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": ".overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 43.89281914893617}, {"name": "io_write_bytes", "value": 644554752}, {"name": "io.read_bytes", "value": 280080896}, {"name": "io_write_time", "value": 13}, {"name": "io_read_time", "value": 2}]}, {"name": ".start-pulseaudio", "subtests": [{"name": "time", "value": 0.0}, {"name": "cpu_percent", "value": 0}]}, {"name": ".install", "subtests": [{"name": "time", "value": 4.796676158905029}, {"name": "cpu_percent", "value": 31.990625}]}, {"name": ".stage-files", "subtests": [{"name": "time", "value": 0.0005083084106445312}, {"name": "cpu_percent", "value": 0}]}, {"name": ".run-tests", "subtests": [{"name": "time", "value": 43.10490703582764}, {"name": "cpu_percent", "value": 45.44553571428571}]}, {"name": ".uninstall", "subtests": [{"name": "time", "value": 0.0005350112915039062}, {"name": "cpu_percent", "value": 0}]}]}
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - Total resource usage - Wall time: 47s; CPU: Can't collect data; Read bytes: 280080896; Write bytes: 644554752; Read time: 2; Write time: 13
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - TinderboxPrint: I/O read bytes / time<br/>280,080,896 / 2
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - TinderboxPrint: I/O write bytes / time<br/>644,554,752 / 13
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - TinderboxPrint: CPU idle<br/>211.8 (56.1%)
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - TinderboxPrint: CPU system<br/>42.9 (11.4%)
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - TinderboxPrint: CPU user<br/>122.3 (32.4%)
[task 2023-06-09T07:31:02.240Z] 07:31:02 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-09T07:31:02.241Z] 07:31:02 INFO - install - Wall time: 5s; CPU: 32%; Read bytes: 318464; Write bytes: 257626112; Read time: 0; Write time: 5
[task 2023-06-09T07:31:02.241Z] 07:31:02 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-09T07:31:02.241Z] 07:31:02 INFO - run-tests - Wall time: 43s; CPU: 45%; Read bytes: 279074816; Write bytes: 302313472; Read time: 2; Write time: 8
[task 2023-06-09T07:31:02.241Z] 07:31:02 INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-06-09T07:31:02.253Z] 07:31:02 WARNING - returning nonzero exit status 2
[taskcluster 2023-06-09T07:31:02.358Z] Exit Code: 2
[taskcluster 2023-06-09T07:31:02.358Z] User Time: 15.625ms
[taskcluster 2023-06-09T07:31:02.358Z] Kernel Time: 62.5ms
[taskcluster 2023-06-09T07:31:02.358Z] Wall Time: 8m59.9066043s
[taskcluster 2023-06-09T07:31:02.358Z] Result: FAILED
[taskcluster 2023-06-09T07:31:02.358Z] === Task Finished ===
[taskcluster 2023-06-09T07:31:02.358Z] Task Duration: 8m59.9099143s
Comment 1•2 years ago
|
||
Set release status flags based on info from the regressing bug 1756814
:hiro, since you are the author of the regressor, bug 1756814, could you take a look?
For more information, please visit BugBot documentation.
Comment hidden (Intermittent Failures Robot) |
Comment 3•2 years ago
|
||
I tried a bunch of retrigger TV runs, https://treeherder.mozilla.org/jobs?repo=try&revision=ca83c082ac58519eccb753fe01d5ef27bd5dd1d6 . But I couldn't see the failure at all.
For future references a couple of lines around the failure are;
[task 2023-06-09T07:30:54.220Z] 07:30:54 INFO - GECKO(9152) | [Parent 7116, IPC I/O Parent] WARNING: ConnectNamedPipe timed out!: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:327
[task 2023-06-09T07:30:54.224Z] 07:30:54 INFO - GECKO(9152) | [Parent 7116, Main Thread] WARNING: content process pid = 9888 crashed without leaving a minidump behind: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:4481
[task 2023-06-09T07:30:54.225Z] 07:30:54 ERROR - GECKO(9152) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
Is this something related to bug 1832020? I am totally unsure.
Anyway, I will keep my eyes on this failure for a while.
Description
•