Closed Bug 1940526 Opened 1 month ago Closed 4 days ago

Intermittent Assertion failure: work_queue_.empty(), at /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:543

Categories

(Core :: IPC, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: assertion, intermittent-failure)

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


[task 2025-01-08T17:18:25.548Z] 17:18:25     INFO -  TEST-PASS | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/0 | test completed (time: 5ms)
[task 2025-01-08T17:18:25.548Z] 17:18:25     INFO -  TEST-START | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/1
[task 2025-01-08T17:18:25.548Z] 17:18:25     INFO -  TEST-PASS | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/1 | test completed (time: 5ms)
[task 2025-01-08T17:18:25.548Z] 17:18:25     INFO -  TEST-PASS | GTest unit test: passed
[task 2025-01-08T17:18:25.549Z] 17:18:25     INFO -  Passed: 12324
[task 2025-01-08T17:18:25.549Z] 17:18:25     INFO -  Failed: 0
[task 2025-01-08T17:18:25.549Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: '!gBasePath', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:1660
[task 2025-01-08T17:18:25.550Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: profile-do-change must precede profile-before-change-qm!: file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:1661
[task 2025-01-08T17:18:25.550Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: Problem removing profile directory: file /builds/worker/workspace/obj-build/dist/include/testing/TestHarness.h:108
[task 2025-01-08T17:18:25.550Z] 17:18:25     INFO -  [ERROR glean_core::database] Failed to record metric 'dirtybit' into glean_internal_info: Error { kind: Rkv(IoError(Os { code: 3, kind: NotFound, message: "The system cannot find the path specified." })) }
[task 2025-01-08T17:18:25.551Z] 17:18:25     INFO -  [ERROR glean_core] Can't persist ping lifetime data: Error { kind: Rkv(IoError(Os { code: 3, kind: NotFound, message: "The system cannot find the path specified." })) }
[task 2025-01-08T17:18:25.551Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: '!aObserver', file /builds/worker/checkouts/gecko/xpcom/ds/nsObserverService.cpp:238
[task 2025-01-08T17:18:25.552Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: IPC message 'PSocketProcess::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-08T17:18:25.552Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: IPC message 'PRDD::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-08T17:18:25.552Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.553Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.553Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.554Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.554Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.554Z] 17:18:25     INFO -  [Socket 8296, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.555Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: Unregistering kCookieBannerServiceModePref callback failed: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/toolkit/components/cookiebanners/nsCookieBannerService.cpp:82
[task 2025-01-08T17:18:25.555Z] 17:18:25     INFO -  [Parent 4168, Main Thread] WARNING: Unregistering kCookieBannerServiceModePBMPref callback failed: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/toolkit/components/cookiebanners/nsCookieBannerService.cpp:87
[task 2025-01-08T17:18:25.556Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.556Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.556Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.557Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.557Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.557Z] 17:18:25     INFO -  [RDD 7144, Main Thread] WARNING: XPCOM object StringBuffer released from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:216
[task 2025-01-08T17:18:25.558Z] 17:18:25     INFO -  [4168] Assertion failure: work_queue_.empty(), at /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:543
[task 2025-01-08T17:18:25.558Z] 17:18:25     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2025-01-08T17:18:54.009Z] 17:18:54     INFO -  #01: MessageLoop::DeletePendingTasks() [ipc/chromium/src/base/message_loop.cc:543]
[task 2025-01-08T17:18:54.014Z] 17:18:54     INFO -  #02: MessageLoop::~MessageLoop() [ipc/chromium/src/base/message_loop.cc:324]
[task 2025-01-08T17:18:54.014Z] 17:18:54     INFO -  #03: base::Thread::ThreadMain() [ipc/chromium/src/base/thread.cc:199]
[task 2025-01-08T17:18:54.014Z] 17:18:54     INFO -  #04: (anonymous namespace)::ThreadFunc(void*) [ipc/chromium/src/base/platform_thread_win.cc:20]
[task 2025-01-08T17:18:54.018Z] 17:18:54     INFO -  fix-stacks: error: failed to read debug info file `wkernel32.pdb` for `C:\Windows\System32\KERNEL32.DLL`
[task 2025-01-08T17:18:54.018Z] 17:18:54     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2025-01-08T17:18:54.019Z] 17:18:54     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2025-01-08T17:18:54.019Z] 17:18:54     INFO -  #05: BaseThreadInitThunk [C:\Windows\System32\KERNEL32.DLL + 0x17374]
[task 2025-01-08T17:18:54.124Z] 17:18:54     INFO -  #06: patched_BaseThreadInitThunk(int, void*, void*) [toolkit/xre/dllservices/mozglue/WindowsDllBlocklist.cpp:562]
[task 2025-01-08T17:18:54.130Z] 17:18:54     INFO -  fix-stacks: error: failed to read debug info file `wntdll.pdb` for `C:\Windows\SYSTEM32\ntdll.dll`
[task 2025-01-08T17:18:54.130Z] 17:18:54     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2025-01-08T17:18:54.131Z] 17:18:54     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2025-01-08T17:18:54.131Z] 17:18:54     INFO -  #07: RtlUserThreadStart [C:\Windows\SYSTEM32\ntdll.dll + 0x4cc91]
[task 2025-01-08T17:18:54.131Z] 17:18:54     INFO -  gtest INFO | gtest | process wait complete, returncode=2147483651
[task 2025-01-08T17:18:54.132Z] 17:18:54     INFO -  mozcrash checking D:\task_173635418301090\build\tests\gtest for minidumps...
[task 2025-01-08T17:18:54.132Z] 17:18:54  WARNING -  gtest TEST-UNEXPECTED-FAIL | gtest | test failed with return code 2147483651
[task 2025-01-08T17:18:54.132Z] 17:18:54     INFO -  gtest INFO | rungtests.py exits with code 1
[task 2025-01-08T17:18:54.175Z] 17:18:54     INFO - Return code: 1
[task 2025-01-08T17:18:54.182Z] 17:18:54     INFO - TinderboxPrint: gtest-gtest<br/>12324/0
[task 2025-01-08T17:18:54.182Z] 17:18:54  WARNING - setting return code to 2
[task 2025-01-08T17:18:54.182Z] 17:18:54     INFO - The gtest suite: gtest ran with return status: FAILURE
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running post-action listener: _package_coverage_data
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running post-action listener: _resource_record_post_action
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running post-action listener: process_java_coverage_data
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - [mozharness: 2025-01-08 17:18:54.183056Z] Finished run-tests step (success)
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - [mozharness: 2025-01-08 17:18:54.183056Z] Running uninstall step.
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running pre-action listener: _resource_record_pre_action
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running main action method: uninstall
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Skipping uninstall for non-MSIX test
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running post-action listener: _resource_record_post_action
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - [mozharness: 2025-01-08 17:18:54.183594Z] Finished uninstall step (success)
[task 2025-01-08T17:18:54.183Z] 17:18:54     INFO - Running post-run listener: _resource_record_post_run
[task 2025-01-08T17:18:55.082Z] 17:18:55     INFO - Validating Perfherder data against D:\task_173635418301090\mozharness\external_tools\performance-artifact-schema.json
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "gtest.gtest.overall", "extraOptions": ["taskcluster-Standard_F8s_v2"], "subtests": [{"name": "cpu_percent", "value": 53.315475927561806}, {"name": "io_write_bytes", "value": 1972179968}, {"name": "io.read_bytes", "value": 1928343552}, {"name": "io_write_time", "value": 8}, {"name": "io_read_time", "value": 425}]}, {"name": "gtest.gtest.start-pulseaudio", "subtests": [{"name": "time", "value": 0.0}, {"name": "cpu_percent", "value": 0}]}, {"name": "gtest.gtest.install", "subtests": [{"name": "time", "value": 3.921999999999997}, {"name": "cpu_percent", "value": 50.76176470588236}]}, {"name": "gtest.gtest.stage-files", "subtests": [{"name": "time", "value": 0.1869999999999834}, {"name": "cpu_percent", "value": 50.0}]}, {"name": "gtest.gtest.run-tests", "subtests": [{"name": "time", "value": 1129.828}, {"name": "cpu_percent", "value": 53.321969999113676}]}, {"name": "gtest.gtest.uninstall", "subtests": [{"name": "time", "value": 0.0}, {"name": "cpu_percent", "value": 0}]}]}
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - Total resource usage - Wall time: 1135s; CPU: Can't collect data; Read bytes: 1928343552; Write bytes: 1972179968; Read time: 425; Write time: 8
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - TinderboxPrint: I/O read bytes / time<br/>1,928,343,552 / 425
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - TinderboxPrint: I/O write bytes / time<br/>1,972,179,968 / 8
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - TinderboxPrint: CPU idle<br/>4,224.8 (46.5%)
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - TinderboxPrint: CPU system<br/>1,567.2 (17.2%)
[task 2025-01-08T17:18:55.087Z] 17:18:55     INFO - TinderboxPrint: CPU user<br/>3,275.0 (36.0%)
[task 2025-01-08T17:18:55.092Z] 17:18:55     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-08T17:18:55.096Z] 17:18:55     INFO - install - Wall time: 4s; CPU: 51%; Read bytes: 155648; Write bytes: 33386496; Read time: 0; Write time: 0
[task 2025-01-08T17:18:55.099Z] 17:18:55     INFO - stage-files - Wall time: 0s; CPU: 50%; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-08T17:18:55.157Z] 17:18:55     INFO - run-tests - Wall time: 1130s; CPU: 53%; Read bytes: 1928187904; Write bytes: 1885967360; Read time: 425; Write time: 8
[task 2025-01-08T17:18:55.178Z] 17:18:55     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-08T17:18:59.332Z] 17:18:59  WARNING - returning nonzero exit status 2
[taskcluster 2025-01-08T17:18:59.515Z]    Exit Code: 2
[taskcluster 2025-01-08T17:18:59.515Z]    User Time: 0s
[taskcluster 2025-01-08T17:18:59.515Z]  Kernel Time: 15.625ms
[taskcluster 2025-01-08T17:18:59.515Z]    Wall Time: 21m4.6044056s
[taskcluster 2025-01-08T17:18:59.515Z]       Result: FAILED
[taskcluster 2025-01-08T17:18:59.515Z] === Task Finished ===
[taskcluster 2025-01-08T17:18:59.515Z] Task Duration: 21m4.6054676s
[taskcluster 2025-01-08T17:19:00.034Z] Uploading artifact public/test_info/system-info.log from file D:\task_173635418301090\build\blobber_upload_dir\system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2025-04-08T16:12:20.087Z
[taskcluster 2025-01-08T17:19:00.036Z] Uploading artifact public/test_info/resource-usage.json from file D:\task_173635418301090\build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-04-08T16:12:20.087Z
[taskcluster 2025-01-08T17:19:00.037Z] Uploading artifact public/test_info/profile_resource-usage.json from file D:\task_173635418301090\build\blobber_upload_dir\profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2025-04-08T16:12:20.087Z
[taskcluster 2025-01-08T17:19:00.038Z] Uploading artifact public/logs/localconfig.json from file D:\task_173635418301090\logs\localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2025-04-08T16:12:20.087Z
[taskcluster 2025-01-08T17:19:00.595Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-04-08T16:12:20.087Z
[taskcluster:error] exit status 2

Status: NEW → RESOLVED
Closed: 4 days ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.