1841671 - Intermittent toolkit/components/extensions/test/mochitest/test_startup_canary.html (finished) | single tracking bug

Status: RESOLVED INCOMPLETE

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-07-04T16:35:45.774Z] 16:35:45     INFO - TEST-START | toolkit/components/extensions/test/mochitest/test_startup_canary.html
[task 2023-07-04T16:35:45.838Z] 16:35:45     INFO - GECKO(3064) | MEMORY STAT | vsize 2111971MB | vsizeMaxContiguous 65177062MB | residentFast 88MB | heapAllocated 12MB
[task 2023-07-04T16:35:45.854Z] 16:35:45     INFO - TEST-OK | toolkit/components/extensions/test/mochitest/test_startup_canary.html | took 70ms
[task 2023-07-04T16:35:45.869Z] 16:35:45     INFO - TEST-START | Shutdown
[task 2023-07-04T16:35:45.884Z] 16:35:45     INFO - Passed:  4956
[task 2023-07-04T16:35:45.885Z] 16:35:45     INFO - Failed:  0
[task 2023-07-04T16:35:45.885Z] 16:35:45     INFO - Todo:    1
[task 2023-07-04T16:35:45.886Z] 16:35:45     INFO - Mode:    e10s
[task 2023-07-04T16:35:45.887Z] 16:35:45     INFO - Slowest: 10976ms - /tests/toolkit/components/extensions/test/mochitest/test_ext_idle.html
[task 2023-07-04T16:35:45.888Z] 16:35:45     INFO - SimpleTest FINISHED
[task 2023-07-04T16:35:45.888Z] 16:35:45     INFO - TEST-INFO | Ran 1 Loops
[task 2023-07-04T16:35:45.889Z] 16:35:45     INFO - SimpleTest FINISHED
[task 2023-07-04T16:35:45.900Z] 16:35:45     INFO - GECKO(3064) | Exiting due to channel error.
[task 2023-07-04T16:35:45.910Z] 16:35:45     INFO - GECKO(3064) | Exiting due to channel error.
[task 2023-07-04T16:38:51.049Z] 16:38:51     INFO -  WARNING | IO Completion Port failed to signal process shutdown
[task 2023-07-04T16:38:51.049Z] 16:38:51     INFO -  Parent process 3064 exited with children alive:
[task 2023-07-04T16:38:51.050Z] 16:38:51     INFO -  PIDS: 3012, 8540, 1060, 8328, 10032, 4740, 964, 4224, 7972, 2456
[task 2023-07-04T16:38:51.050Z] 16:38:51     INFO -  Attempting to kill them, but no guarantee of success
[task 2023-07-04T16:39:34.676Z] 16:39:34     INFO -  console.error: (new TypeError("connection not specified or invalid.", "resource://gre/modules/Sqlite.sys.mjs", 1522))
[task 2023-07-04T16:39:34.681Z] 16:39:34     INFO -  console.error: (new TypeError("can't access property \"executeBeforeShutdown\", db is undefined", "resource://gre/modules/PlacesUtils.sys.mjs", 1467))
[task 2023-07-04T16:41:34.681Z] 16:41:34     INFO -  console.error: (new TypeError("can't access property \"executeTransaction\", db is undefined", "resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs", 175))
[task 2023-07-04T16:41:55.937Z] 16:41:55     INFO - Buffered messages finished
[task 2023-07-04T16:41:55.938Z] 16:41:55    ERROR - TEST-UNEXPECTED-TIMEOUT | toolkit/components/extensions/test/mochitest/test_startup_canary.html (finished) | application timed out after 370 seconds with no output
[task 2023-07-04T16:41:55.939Z] 16:41:55  WARNING - Force-terminating active process(es).
[task 2023-07-04T16:41:55.939Z] 16:41:55     INFO - Determining child pids from psutil...
[task 2023-07-04T16:41:55.939Z] 16:41:55  WARNING - Failed to lookup children of pid 3064
[task 2023-07-04T16:41:55.940Z] 16:41:55     INFO - ==> process 9276 launched child process 4356 ("Z:\task_168848643082284\build\application\firefox\firefox.exe" -contentproc --channel=2228 -parentBuildID 20230704152225 -prefsHandle 2156 -prefMapHandle 2148 -prefsLen 22137 -prefMapSize 250508 -appDir "Z:\task_168848643082284\build\application\firefox\browser" - {a1951a2a-b944-485f-92cc-35195810cbc8} 9276 "\\.\pipe\gecko-crash-server-pipe.9276" 24c46df8a10 gpu)
<...>
[task 2023-07-04T16:41:56.728Z] 16:41:56     INFO - mozcrash Writing a dump to C:\Users\task_168848643082284\AppData\Local\Temp\tmpeju2qpkd.mozrunner\minidumps\1412d4c5-4075-4639-9c5f-8a198c679df1.dmp for [3064]
[task 2023-07-04T16:41:56.729Z] 16:41:56  WARNING - mozcrash unable to get handle for pid 3064: 87
[task 2023-07-04T16:41:56.729Z] 16:41:56  WARNING - mozcrash kill_pid(): unable to get handle for pid 3064: 87
[task 2023-07-04T16:58:36.733Z] 16:58:36     INFO - Automation Error: mozharness timed out after 1000 seconds running ['Z:\\task_168848643082284\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_168848643082284\\build\\tests\\mochitest\\runtests.py', 'dom/abort/tests/mochitest.ini', 'dom/base/test/mochitest.ini', 'dom/cache/test/mochitest/mochitest.ini', 'dom/crypto/test/mochitest.ini', 'dom/file/tests/mochitest.ini', 'dom/fs/test/common/mochitest.ini', 'dom/fs/test/mochitest/mochitest.ini', 'dom/fs/test/mochitest/worker/mochitest.ini', 'dom/ipc/tests/mochitest.ini', 'dom/network/tests/mochitest.ini', 'dom/origin-trials/tests/mochitest/mochitest.ini', 'dom/payments/test/mochitest.ini', 'dom/permission/tests/mochitest.ini', 'dom/promise/tests/mochitest.ini', 'dom/security/sanitizer/tests/mochitest/mochitest.ini', 'dom/security/test/cors/mochitest.ini', 'dom/security/test/general/mochitest.ini', 'dom/tests/mochitest/ajax/mochikit/mochitest.ini', 'dom/tests/mochitest/bugs/mochitest.ini', 'dom/tests/mochitest/dom-level2-html/mochitest.ini', 'dom/tests/mochitest/webcomponents/mochitest.ini', 'dom/url/tests/mochitest.ini', 'dom/vr/test/mochitest/mochitest.ini', 'dom/webshare/test/mochitest/mochitest.ini', 'dom/websocket/tests/mochitest.ini', 'dom/websocket/tests/mochitest_http2.ini', 'gfx/tests/mochitest/mochitest.ini', 'ipc/glue/test/browser/mochitest_audio_off.ini', 'ipc/glue/test/browser/mochitest_audio_on.ini', 'js/xpconnect/tests/mochitest/hasinstance/mochitest.ini', 'layout/svg/tests/mochitest.ini', 'layout/xul/test/mochitest.ini', 'mobile/android/actors/tests/mochitests/mochitest.ini', 'parser/htmlparser/tests/mochitest/mochitest.ini', 'testing/mochitest/baselinecoverage/plain/mochitest.ini', 'testing/mochitest/tests/MochiKit-1.4.2/tests/mochitest.ini', 'toolkit/components/extensions/test/mochitest/mochitest-remote.ini', 'toolkit/components/pdfjs/test/mochitest.ini', 'toolkit/components/url-classifier/tests/mochitest/mochitest.ini', 'toolkit/components/windowcreator/test/mochitest.ini', 'toolkit/xre/test/mochitest.ini', 'tools/code-coverage/tests/mochitest/mochitest.ini', '--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=Z:\\task_168848643082284\\build\\application\\firefox\\firefox.exe', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/TNwo9pXYTlqZDGg8bstUaQ/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--quiet', '--log-errorsummary=Z:\\task_168848643082284\\build\\blobber_upload_dir\\mochitest-plain_errorsummary.log', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--log-raw=-', '--chunk-by-dir=4']
[task 2023-07-04T16:58:36.739Z] 16:58:36     INFO - Return code: 1
[task 2023-07-04T16:58:36.740Z] 16:58:36    ERROR - No suite end message was emitted by this harness.
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - TinderboxPrint: mochitest-mochitest-plain<br/>1692/0/0
[task 2023-07-04T16:58:36.740Z] 16:58:36  WARNING - setting return code to 2
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - The mochitest suite: mochitest-plain ran with return status: FAILURE
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - Running post-action listener: _package_coverage_data
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - Running post-action listener: _resource_record_post_action
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - Running post-action listener: process_java_coverage_data
[task 2023-07-04T16:58:36.740Z] 16:58:36     INFO - [mozharness: 2023-07-04 16:58:36.740540Z] Finished run-tests step (success)
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - [mozharness: 2023-07-04 16:58:36.740540Z] Running uninstall step.
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - Running pre-action listener: _resource_record_pre_action
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - Running main action method: uninstall
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - Skipping uninstall for non-MSIX test
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - Running post-action listener: _resource_record_post_action
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - [mozharness: 2023-07-04 16:58:36.741134Z] Finished uninstall step (success)
[task 2023-07-04T16:58:36.741Z] 16:58:36     INFO - Running post-run listener: _resource_record_post_run
[task 2023-07-04T16:58:36.952Z] 16:58:36     INFO - instance_metadata.json not found; unable to determine instance type
[task 2023-07-04T16:58:36.970Z] 16:58:36     INFO - Validating Perfherder data against Z:\task_168848643082284\mozharness\external_tools\performance-artifact-schema.json
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-plain.overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 26.324905200433346}, {"name": "io_write_bytes", "value": 7228074496}, {"name": "io.read_bytes", "value": 7137936896}, {"name": "io_write_time", "value": 217}, {"name": "io_read_time", "value": 595}]}, {"name": "mochitest.mochitest-plain.start-pulseaudio", "subtests": [{"name": "time", "value": 0.013030052185058594}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-plain.install", "subtests": [{"name": "time", "value": 3.336138963699341}, {"name": "cpu_percent", "value": 29.54166666666666}]}, {"name": "mochitest.mochitest-plain.stage-files", "subtests": [{"name": "time", "value": 0.0}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-plain.run-tests", "subtests": [{"name": "time", "value": 2773.2055809497833}, {"name": "cpu_percent", "value": 26.322151898734155}]}, {"name": "mochitest.mochitest-plain.uninstall", "subtests": [{"name": "time", "value": 0.0}, {"name": "cpu_percent", "value": 0}]}]}
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - Total resource usage - Wall time: 2776s; CPU: Can't collect data; Read bytes: 7137936896; Write bytes: 7228074496; Read time: 595; Write time: 217
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - TinderboxPrint: I/O read bytes / time<br/>7,137,936,896 / 595
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - TinderboxPrint: I/O write bytes / time<br/>7,228,074,496 / 217
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - TinderboxPrint: CPU idle<br/>16,376.3 (73.7%)
[task 2023-07-04T16:58:36.973Z] 16:58:36     INFO - TinderboxPrint: CPU system<br/>1,891.3 (8.5%)
[task 2023-07-04T16:58:36.974Z] 16:58:36     INFO - TinderboxPrint: CPU user<br/>3,940.9 (17.7%)
[task 2023-07-04T16:58:36.974Z] 16:58:36     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-07-04T16:58:36.975Z] 16:58:36     INFO - install - Wall time: 3s; CPU: 30%; Read bytes: 221696; Write bytes: 187977728; Read time: 0; Write time: 5
[task 2023-07-04T16:58:36.975Z] 16:58:36     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-07-04T16:58:36.987Z] 16:58:36     INFO - run-tests - Wall time: 2773s; CPU: 26%; Read bytes: 7137105408; Write bytes: 6990858752; Read time: 595; Write time: 212
[task 2023-07-04T16:58:36.995Z] 16:58:36     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-07-04T16:58:37.623Z] 16:58:37  WARNING - returning nonzero exit status 2
[taskcluster 2023-07-04T16:58:37.717Z]    Exit Code: 2
[taskcluster 2023-07-04T16:58:37.717Z]    User Time: 0s
[taskcluster 2023-07-04T16:58:37.717Z]  Kernel Time: 31.25ms
[taskcluster 2023-07-04T16:58:37.717Z]    Wall Time: 51m5.8057518s
[taskcluster 2023-07-04T16:58:37.717Z]       Result: FAILED
[taskcluster 2023-07-04T16:58:37.717Z] === Task Finished ===
[taskcluster 2023-07-04T16:58:37.717Z] Task Duration: 51m5.8266409s
[taskcluster 2023-07-04T16:58:38.003Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:39.403Z] Uploading artifact public/test_info/manifests.list from file build\blobber_upload_dir\manifests.list with content encoding "gzip", mime type "application/octet-stream" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:39.904Z] Uploading artifact public/test_info/mochitest-plain_errorsummary.log from file build\blobber_upload_dir\mochitest-plain_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:40.393Z] Uploading artifact public/test_info/mozilla-test-fail-screenshot_67c6y90m.png from file build\blobber_upload_dir\mozilla-test-fail-screenshot_67c6y90m.png with content encoding "identity", mime type "image/png" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:42.226Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:42.891Z] Uploading artifact public/test_info/system-info.log from file build\blobber_upload_dir\system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2024-07-03T15:25:49.388Z
[taskcluster 2023-07-04T16:58:43.378Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2024-07-03T15:25:49.388Z
[taskcluster:error] exit status 2

Comment 1

[Intermittent Failures Robot]

1 failures in 2956 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841671&startday=2023-07-03&endday=2023-07-09&tree=all

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 3

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=453651798&repo=mozilla-beta

Comment 4

[Intermittent Failures Robot]

1 failures in 3805 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• linux2204-64-wayland-shippable: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841671&startday=2024-04-01&endday=2024-04-07&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 4336 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux2204-64-wayland: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841671&startday=2024-04-22&endday=2024-04-28&tree=all

Comment 6

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 7

[Intermittent Failures Robot]

Summary

1 failures in 5035 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• linux2204-64-wayland: 1
  • opt: 1

Table

	no_variant
linux2204-64-wayland--/opt	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841671&startday=2025-03-17&endday=2025-03-23&tree=all