Closed
Bug 1911556
Opened 1 year ago
Closed 1 year ago
Intermittent toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js | single tracking bug
Categories
(Core :: Privacy: Anti-Tracking, defect, P5)
Core
Privacy: Anti-Tracking
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: tszentpeteri [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=469187914&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/R0aAA4DhSd-IDF7P2OyObw/runs/0/artifacts/public/logs/live_backing.log
[task 2024-08-05T11:03:40.988Z] 11:03:40 INFO - TEST-PASS | toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js | The build click state is correct. - "OptOut" == "OptOut" -
[task 2024-08-05T11:03:40.988Z] 11:03:40 INFO - Leaving test bound test_embedded_iframe
[task 2024-08-05T11:03:40.988Z] 11:03:40 INFO - Buffered messages finished
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js | waiting for vsync to be disabled - timed out after 50 tries. - false == true -
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - Stack trace:
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:ensureVsyncDisabled:607
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:nextTest:782
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:testScope/test_finish/<:1811
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:run:1731
[task 2024-08-05T11:03:40.989Z] 11:03:40 INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js | vsync remained enabled at the end of the test. Is there an animation still running? Consider talking to the performance team for tips to solve this. - false == true -
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - Stack trace:
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:ensureVsyncDisabled:608
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:nextTest:782
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:testScope/test_finish/<:1811
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - chrome://mochikit/content/browser-test.js:run:1731
[task 2024-08-05T11:03:40.990Z] 11:03:40 INFO - GECKO(2587) | MEMORY STAT | vsize 8346MB | residentFast 398MB | heapAllocated 144MB
[task 2024-08-05T11:03:40.991Z] 11:03:40 INFO - TEST-OK | toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js | took 18935ms
[task 2024-08-05T11:03:40.991Z] 11:03:40 INFO - GECKO(2587) | [Child 2592: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 118632400 == 1 [pid = 2592] [id = 3]
[task 2024-08-05T11:03:40.991Z] 11:03:40 INFO - GECKO(2587) | [Child 2592: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (10f626000) [pid = 2592] [serial = 7] [outer = 0]
[task 2024-08-05T11:03:40.992Z] 11:03:40 INFO - GECKO(2587) | [Child 2592: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (118632800) [pid = 2592] [serial = 8] [outer = 10f626000]
[task 2024-08-05T11:03:40.992Z] 11:03:40 INFO - checking window state
[task 2024-08-05T11:03:40.992Z] 11:03:40 INFO - GECKO(2587) | must wait for focus
[task 2024-08-05T11:03:49.333Z] 11:03:49 INFO - GECKO(2587) | [Child 2590: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 11f41e000 == 0 [pid = 2590] [id = 3] [url = about:blank]
[task 2024-08-05T11:03:54.073Z] 11:03:54 INFO - GECKO(2587) | [Child 2590: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (103b24c00) [pid = 2590] [serial = 9] [outer = 0] [url = about:blank]
[task 2024-08-05T11:03:58.767Z] 11:03:58 INFO - GECKO(2587) | [Child 2590: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (11f41e400) [pid = 2590] [serial = 10] [outer = 0] [url = about:blank]
[task 2024-08-05T11:10:08.795Z] 11:10:08 INFO - TEST-UNEXPECTED-TIMEOUT | toolkit/components/cookiebanners/test/browser/browser_bannerClicking_runContext.js (finished) | application timed out after 370 seconds with no output
[task 2024-08-05T11:10:08.795Z] 11:10:08 INFO - TEST-INFO
[task 2024-08-05T11:10:08.796Z] 11:10:08 INFO - Buffered messages finished
[task 2024-08-05T11:10:08.796Z] 11:10:08 WARNING - Force-terminating active process(es).
[task 2024-08-05T11:10:08.796Z] 11:10:08 INFO - Determining child pids from psutil...
[task 2024-08-05T11:10:08.798Z] 11:10:08 INFO - [2588, 2589, 2590, 2591, 2592, 2594, 2689, 2690, 2691]
[task 2024-08-05T11:10:08.798Z] 11:10:08 INFO - ==> process 2587 launched child process 2588
[task 2024-08-05T11:10:08.799Z] 11:10:08 INFO - ==> process 2587 launched child process 2589
[task 2024-08-05T11:10:08.799Z] 11:10:08 INFO - ==> process 2587 launched child process 2590
[task 2024-08-05T11:10:08.799Z] 11:10:08 INFO - ==> process 2587 launched child process 2591
[task 2024-08-05T11:10:08.800Z] 11:10:08 INFO - ==> process 2587 launched child process 2592
<...>
[task 2024-08-05T11:10:08.819Z] 11:10:08 INFO - ==> process 2587 launched child process 2690
[task 2024-08-05T11:10:08.819Z] 11:10:08 INFO - ==> process 2587 launched child process 2691
[task 2024-08-05T11:10:08.820Z] 11:10:08 INFO - Found child pids: {2688, 2689, 2690, 2691, 2588, 2589, 2590, 2591, 2592, 2593, 2594, 2595, 2597, 2601, 2602, 2603, 2604, 2605, 2606, 2607, 2608, 2609, 2610, 2611, 2612, 2613, 2614, 2615, 2616, 2617, 2622, 2623, 2624, 2625, 2632, 2633, 2634, 2635, 2636, 2637, 2638, 2639, 2644, 2645, 2646, 2647, 2648, 2649, 2650, 2651, 2652, 2653, 2654, 2655, 2656, 2657, 2662, 2663, 2664, 2665, 2666, 2667, 2668, 2669, 2670, 2671, 2672, 2674, 2681, 2686, 2687}
[task 2024-08-05T11:10:08.820Z] 11:10:08 INFO - Failed to get child procs
[task 2024-08-05T11:10:08.820Z] 11:10:08 INFO - Killing process: 2688
[task 2024-08-05T11:10:08.820Z] 11:10:08 INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-08-05T11:10:08.821Z] 11:10:08 INFO - Can't trigger Breakpad, process no longer exists
[task 2024-08-05T11:10:08.821Z] 11:10:08 INFO - Killing process: 2689
<...>
[task 2024-08-05T11:10:08.880Z] 11:10:08 INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-08-05T11:10:08.986Z] 11:10:08 INFO - psutil found pid 2587 dead
[task 2024-08-05T11:26:49.096Z] 11:26:49 INFO - Automation Error: mozharness timed out after 1000 seconds running ['/opt/worker/tasks/task_172285436534151/build/venv/bin/python', '-u', '/opt/worker/tasks/task_172285436534151/build/tests/mochitest/runtests.py', 'browser/base/content/test/caps/browser.toml', 'browser/base/content/test/menubar/browser.toml', 'browser/base/content/test/popupNotifications/browser.toml', 'browser/base/content/test/tabcrashed/browser.toml', 'browser/components/attribution/test/browser/browser.toml', 'browser/components/enterprisepolicies/tests/browser/disable_fxscreenshots/browser.toml', 'browser/components/newtab/test/browser/abouthomecache/browser.toml', 'browser/components/privatebrowsing/test/browser/browser.toml', 'browser/components/sessionstore/test/browser_oldformat.toml', 'browser/components/uitour/test/browser.toml', 'browser/extensions/formautofill/test/browser/heuristics/browser.toml', 'dom/base/test/browser.toml', 'dom/ipc/tests/JSProcessActor/browser.toml', 'dom/security/test/https-first/browser.toml', 'editor/libeditor/tests/browser.toml', 'layout/xul/test/browser.toml', 'toolkit/components/aboutprocesses/tests/browser/browser.toml', 'toolkit/components/cookiebanners/test/browser/browser.toml', 'toolkit/components/narrate/test/browser.toml', 'toolkit/components/remotebrowserutils/tests/browser/browser.toml', 'toolkit/components/windowcreator/test/browser.toml', 'uriloader/exthandler/tests/mochitest/browser.toml', '--setpref=layout.css.stylo-threads=4', '--setpref=network.process.enabled=true', '--setpref=network.http.network_access_on_socket_process.enabled=true', '--setpref=layers.d3d11.enable-blacklist=false', '--appname=/opt/worker/tasks/task_172285436534151/build/application/Firefox NightlyDebug.app/Contents/MacOS/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=/opt/worker/tasks/task_172285436534151/build/symbols', '--certificate-path=tests/certs', '--quiet', '--log-errorsummary=/opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/opt/worker/tasks/task_172285436534151/build', '--log-raw=-', '--flavor=browser', '--chunk-by-runtime']
[task 2024-08-05T11:26:49.099Z] 11:26:49 INFO - Return code: -9
[task 2024-08-05T11:26:49.099Z] 11:26:49 WARNING - Got 3 unexpected statuses
[task 2024-08-05T11:26:49.099Z] 11:26:49 ERROR - No suite end message was emitted by this harness.
[task 2024-08-05T11:26:49.099Z] 11:26:49 INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>368/<em class="testfail">3</em>/0
[task 2024-08-05T11:26:49.100Z] 11:26:49 WARNING - setting return code to 2
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - The mochitest suite: mochitest-browser-chrome ran with return status: FAILURE
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running post-action listener: _package_coverage_data
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running post-action listener: _resource_record_post_action
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running post-action listener: process_java_coverage_data
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - [mozharness: 2024-08-05 11:26:49.100369Z] Finished run-tests step (success)
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - [mozharness: 2024-08-05 11:26:49.100408Z] Running uninstall step.
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running pre-action listener: _resource_record_pre_action
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running main action method: uninstall
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Skipping uninstall for non-MSIX test
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running post-action listener: _resource_record_post_action
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - [mozharness: 2024-08-05 11:26:49.100581Z] Finished uninstall step (success)
[task 2024-08-05T11:26:49.100Z] 11:26:49 INFO - Running post-run listener: _resource_record_post_run
[task 2024-08-05T11:26:49.955Z] 11:26:49 INFO - instance_metadata.json not found; unable to determine instance type
[task 2024-08-05T11:26:50.009Z] 11:26:50 INFO - Validating Perfherder data against /opt/worker/tasks/task_172285436534151/mozharness/external_tools/performance-artifact-schema.json
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-browser-chrome.11.overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 15.317947993216368}, {"name": "io_write_bytes", "value": 2057953280}, {"name": "io.read_bytes", "value": 1045331968}, {"name": "io_write_time", "value": 7216}, {"name": "io_read_time", "value": 13611}]}, {"name": "mochitest.mochitest-browser-chrome.11.start-pulseaudio", "subtests": [{"name": "time", "value": 0.00038270000001716653}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.11.install", "subtests": [{"name": "time", "value": 28.017194500000016}, {"name": "cpu_percent", "value": 13.69049935149157}]}, {"name": "mochitest.mochitest-browser-chrome.11.stage-files", "subtests": [{"name": "time", "value": 0.00022898100002066712}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.11.run-tests", "subtests": [{"name": "time", "value": 2606.044233715}, {"name": "cpu_percent", "value": 15.341732637295248}]}, {"name": "mochitest.mochitest-browser-chrome.11.uninstall", "subtests": [{"name": "time", "value": 0.00011188500002390356}, {"name": "cpu_percent", "value": 0}]}]}
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - Total resource usage - Wall time: 2635s; CPU: Can't collect data; Read bytes: 1045331968; Write bytes: 2057953280; Read time: 13611; Write time: 7216
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: I/O read bytes / time<br/>1,045,331,968 / 13,611
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: I/O write bytes / time<br/>2,057,953,280 / 7,216
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: CPU idle<br/>26,983.1 (85.4%)
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: CPU system<br/>512.5 (1.6%)
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: CPU user<br/>4,111.3 (13.0%)
[task 2024-08-05T11:26:50.011Z] 11:26:50 INFO - TinderboxPrint: Swap in / out<br/>1,365,794,816 / 0
[task 2024-08-05T11:26:50.015Z] 11:26:50 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-08-05T11:26:50.020Z] 11:26:50 INFO - install - Wall time: 28s; CPU: 14%; Read bytes: 7491584; Write bytes: 370954240; Read time: 63; Write time: 652
[task 2024-08-05T11:26:50.023Z] 11:26:50 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-08-05T11:26:50.151Z] 11:26:50 INFO - run-tests - Wall time: 2606s; CPU: 15%; Read bytes: 1037340672; Write bytes: 1686974464; Read time: 13515; Write time: 6558
[task 2024-08-05T11:26:50.158Z] 11:26:50 INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-08-05T11:26:54.185Z] 11:26:54 WARNING - returning nonzero exit status 2
[taskcluster 2024-08-05T11:26:54.373Z] Exit Code: 2
[taskcluster 2024-08-05T11:26:54.373Z] User Time: 42m43.521252s
[taskcluster 2024-08-05T11:26:54.373Z] Kernel Time: 2m41.193053s
[taskcluster 2024-08-05T11:26:54.373Z] Wall Time: 47m27.411728s
[taskcluster 2024-08-05T11:26:54.373Z] Result: FAILED
[taskcluster 2024-08-05T11:26:54.373Z] === Task Finished ===
[taskcluster 2024-08-05T11:26:54.373Z] Task Duration: 47m27.419413s
[taskcluster 2024-08-05T11:26:54.623Z] Uploading artifact public/logs/localconfig.json from file /opt/worker/tasks/task_172285436534151/logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:54.937Z] Uploading artifact public/test_info/manifests.list from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/manifests.list with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:55.233Z] Uploading artifact public/test_info/mochitest-browser-chrome_errorsummary.log from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:55.514Z] Uploading artifact public/test_info/mozilla-test-fail-screenshot_v9vg9z2p.png from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/mozilla-test-fail-screenshot_v9vg9z2p.png with content encoding "identity", mime type "image/png" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:55.812Z] Uploading artifact public/test_info/profile_resource-usage.json from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:56.173Z] Uploading artifact public/test_info/resource-usage.json from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:57.027Z] Uploading artifact public/test_info/system-info.log from file /opt/worker/tasks/task_172285436534151/build/blobber_upload_dir/system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2025-08-05T10:22:58.785Z
[taskcluster 2024-08-05T11:26:57.298Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-08-05T10:22:58.785Z
[taskcluster:error] exit status 2
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•