Closed Bug 1839361 Opened 2 years ago Closed 3 months ago

Intermittent xpcshell application crashed [None] | pid: None | single tracking bug

Categories

(Core :: mozglue, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Attachments

(1 obsolete file)

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


[task 2023-06-20T10:08:57.699Z] 10:08:57     INFO -  TEST-START | toolkit/mozapps/update/tests/unit_service_updater/checkUpdaterSigSvc.js
[task 2023-06-20T10:08:58.983Z] 10:08:58  WARNING -  PROCESS-CRASH | application crashed [None] | xpcshell.ini:toolkit/components/search/tests/xpcshell/searchconfigs/test_qwant.js
[task 2023-06-20T10:08:58.983Z] 10:08:58     INFO -  Crash dump filename: C:\Users\task_168724148391196\AppData\Local\Temp\xpc-other-wlclwl2f\2ee44905-3c75-4529-84cf-b1f9c72519ad.dmp
[task 2023-06-20T10:08:58.983Z] 10:08:58     INFO -  stderr from minidump-stackwalk:
[task 2023-06-20T10:08:58.983Z] 10:08:58     INFO -  ERROR MissingHeader - Error reading dump: Missing minidump header (empty minidump?)
[task 2023-06-20T10:08:59.061Z] 10:08:59     INFO -  TEST-PASS | toolkit/mozapps/update/tests/unit_service_updater/checkUpdaterSigSvc.js | took 1377ms
[task 2023-06-20T10:08:59.266Z] 10:08:59     INFO -  >>>>>>>
[task 2023-06-20T10:08:59.266Z] 10:08:59     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2023-06-20T10:08:59.266Z] 10:08:59     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2023-06-20T10:08:59.266Z] 10:08:59     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2023-06-20T10:08:59.266Z] 10:08:59     INFO -  running event loop

The original failure might have been in a search test, but there's no stack, and it is unlikely search would cause the crash being JavaScript only.

The most recent set of failures are all in other locations, some with stacks, some with partials. However, they aren't search related, so moving this across to Core: General.

Component: Search → General
Product: Firefox → Core
Attachment #9384223 - Attachment is obsolete: true

Hello, there's been a recent failure spike that after retriggers & backfills seem to point to Bug 1847098 as seen here. Here is the failure log. Could you take a look please? Thank you!

Flags: needinfo?(lissyx+mozillians)

Can I ask about retriggers and backfills ? My patch touches things that are only related to minidump generation, those tests are browsertime perfs, so except if we expect them to crash, I dont see how it can relate. I'm traveling so I wont be able to have a look before tomorrow at best.

Flags: needinfo?(lissyx+mozillians)

Out of 25 retriggers on the push beneath Bug 1847098 there are only 3 failures, which lack the failure line of PROCESS-CRASH | application crashed [None] | pid: None and on the push that contains the mentioned bug out of 15 retriggers there are 7 failures that contain that line. Here is a snippet of the failures including the process-crash:

[task 2024-02-29T07:13:56.213Z] 07:11:44     INFO -  raptor-browsertime Info: Browsertime pageload ended.
[task 2024-02-29T07:13:56.213Z] 07:13:44 CRITICAL -  raptor-browsertime Critical: Browsertime process timed out after waiting 120 seconds for output
[task 2024-02-29T07:13:56.213Z] 07:13:44     INFO -  raptor-browsertime-android Info: removing reverse socket connections
[task 2024-02-29T07:13:56.213Z] 07:13:44     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/H0ot_G43Qv-V8orFzy8bJA/artifacts/public/build/en-US/target.crashreporter-symbols.zip
[task 2024-02-29T07:13:56.213Z] 07:13:52     INFO -  mozcrash Copy/paste: /builds/task_170918936613035/fetches/minidump-stackwalk/minidump-stackwalk --symbols-url=https://symbols.mozilla.org/ --cyborg=/tmp/tmp5i_z49rk/69d8daaa-afa9-12b5-b599-845ffae98054.trace /tmp/tmp6ds3340f/69d8daaa-afa9-12b5-b599-845ffae98054.dmp /tmp/tmpch9kvuk4
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  mozcrash Saved minidump as /builds/task_170918936613035/workspace/build/blobber_upload_dir/69d8daaa-afa9-12b5-b599-845ffae98054.dmp
[task 2024-02-29T07:13:56.213Z] 07:13:53    ERROR -  PROCESS-CRASH | application crashed [None] | pid: None
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  Process type: unknown
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  Process pid: None
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  Crash dump filename: /tmp/tmp6ds3340f/69d8daaa-afa9-12b5-b599-845ffae98054.dmp
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  stderr from minidump-stackwalk:
[task 2024-02-29T07:13:56.213Z] 07:13:53     INFO -  ERROR MissingSystemInfo - Error processing dump: The system information stream was not found
[task 2024-02-29T07:13:56.213Z] 07:13:55     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2024-02-29T07:13:56.213Z] 07:13:55     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1203
[task 2024-02-29T07:13:56.213Z] 07:13:56     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2024-02-29T07:14:06.701Z] 07:13:56    ERROR -  Traceback (most recent call last):
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -    File "/builds/task_170918936613035/workspace/build/tests/raptor/raptor/raptor.py", line 187, in <module>
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -      main()
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -    File "/builds/task_170918936613035/workspace/build/tests/raptor/raptor/raptor.py", line 136, in main
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -    File "/builds/task_170918936613035/workspace/build/tests/raptor/raptor/browsertime/android.py", line 267, in run_tests
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -    File "/builds/task_170918936613035/workspace/build/tests/raptor/raptor/perftest.py", line 498, in run_tests
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -    File "/builds/task_170918936613035/workspace/build/tests/raptor/raptor/browsertime/base.py", line 1019, in run_test
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -      raise Exception(
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO -  Exception: Browsertime process timed out after waiting 120 seconds for output
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Return code: 1
[task 2024-02-29T07:14:06.701Z] 07:13:56  WARNING - setting return code to 1
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Killing logcat pid 860.
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Copying Raptor results to upload dir:
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - /builds/task_170918936613035/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Copying raptor results from /builds/task_170918936613035/workspace/build/raptor.json to /builds/task_170918936613035/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T07:14:06.701Z] 07:13:56 CRITICAL - Error copying results /builds/task_170918936613035/workspace/build/raptor.json to upload dir /builds/task_170918936613035/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - [Errno 2] No such file or directory: '/builds/task_170918936613035/workspace/build/raptor.json'
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Running post-action listener: _package_coverage_data
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Running post-action listener: _resource_record_post_action
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Running post-action listener: process_java_coverage_data
[task 2024-02-29T07:14:06.701Z] 07:13:56     INFO - Running post-action listener: stop_device
[task 2024-02-29T07:14:06.701Z] 07:13:59     INFO - /data/tombstones/tombstone_00 deleted
[task 2024-02-29T07:14:06.701Z] 07:13:59     INFO - /data/tombstones/tombstone_01 deleted
[task 2024-02-29T07:14:06.701Z] 07:13:59     INFO - Killing logcat pid 860.
[task 2024-02-29T07:14:06.701Z] 07:13:59     INFO - [mozharness: 2024-02-29 07:13:59.644648Z] Finished run-tests step (success)
[task 2024-02-29T07:14:06.701Z] 07:13:59     INFO - Running post-run listener: _resource_record_post_run
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - Total resource usage - Wall time: 1363s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - TinderboxPrint: I/O write bytes / time<br/>0 / 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - install-chrome-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - install - Wall time: 12s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T07:14:06.701Z] 07:14:00     INFO - run-tests - Wall time: 1347s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T07:14:06.701Z] 07:14:01  WARNING - returning nonzero exit status 1

And here is a snippet of a failure without the process-crash:

[task 2024-02-29T06:50:11.258Z] 06:50:02     INFO -  raptor-browsertime Info: CPU / Power usage: 11662
[task 2024-02-29T06:50:11.258Z] 06:50:03     INFO -  raptor-browsertime Info: Browsertime pageload ended.
[task 2024-02-29T06:50:11.258Z] 06:50:04    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at Object.throwDecodedError (/builds/task_170918865886020/fetches/browsertime/node_modules/selenium-webdriver/lib/error.js:524:15)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at parseHttpResponse (/builds/task_170918865886020/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:601:13)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at Executor.execute (/builds/task_170918865886020/fetches/browsertime/node_modules/selenium-webdriver/lib/http.js:529:28)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async Driver.execute (/builds/task_170918865886020/fetches/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:745:17)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async Object.thenFinally [as finally] (/builds/task_170918865886020/fetches/browsertime/node_modules/selenium-webdriver/lib/promise.js:100:5)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async timeout (file:///builds/task_170918865886020/fetches/browsertime/node_modules/browsertime/lib/core/seleniumRunner.js:52:20)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async Iteration.run (file:///builds/task_170918865886020/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:288:11)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async Engine.runByScript (file:///builds/task_170918865886020/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:304:20)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async run (file:///builds/task_170918865886020/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:104:22)
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime Info:     at async file:///builds/task_170918865886020/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:217:1
[task 2024-02-29T06:50:11.258Z] 06:50:04 CRITICAL -  raptor-browsertime Critical: WebDriverError: Failed to decode response from marionette
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-browsertime-android Info: removing reverse socket connections
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2024-02-29T06:50:11.258Z] 06:50:04     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1203
[task 2024-02-29T06:50:11.258Z] 06:50:05     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2024-02-29T06:50:11.258Z] 06:50:06    ERROR -  Traceback (most recent call last):
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -    File "/builds/task_170918865886020/workspace/build/tests/raptor/raptor/raptor.py", line 187, in <module>
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -      main()
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -    File "/builds/task_170918865886020/workspace/build/tests/raptor/raptor/raptor.py", line 136, in main
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -    File "/builds/task_170918865886020/workspace/build/tests/raptor/raptor/browsertime/android.py", line 267, in run_tests
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -    File "/builds/task_170918865886020/workspace/build/tests/raptor/raptor/perftest.py", line 498, in run_tests
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -    File "/builds/task_170918865886020/workspace/build/tests/raptor/raptor/browsertime/base.py", line 1029, in run_test
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -      raise Exception(self.browsertime_failure)
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO -  Exception: WebDriverError: Failed to decode response from marionette
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Return code: 1
[task 2024-02-29T06:50:11.258Z] 06:50:06  WARNING - setting return code to 1
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Killing logcat pid 859.
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Copying Raptor results to upload dir:
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - /builds/task_170918865886020/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Copying raptor results from /builds/task_170918865886020/workspace/build/raptor.json to /builds/task_170918865886020/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T06:50:11.258Z] 06:50:06 CRITICAL - Error copying results /builds/task_170918865886020/workspace/build/raptor.json to upload dir /builds/task_170918865886020/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - [Errno 2] No such file or directory: '/builds/task_170918865886020/workspace/build/raptor.json'
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Running post-action listener: _package_coverage_data
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Running post-action listener: _resource_record_post_action
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Running post-action listener: process_java_coverage_data
[task 2024-02-29T06:50:11.258Z] 06:50:06     INFO - Running post-action listener: stop_device
[task 2024-02-29T06:50:11.258Z] 06:50:09     INFO - /data/tombstones/tombstone_00 deleted
[task 2024-02-29T06:50:11.258Z] 06:50:09     INFO - Killing logcat pid 859.
[task 2024-02-29T06:50:11.258Z] 06:50:09     INFO - [mozharness: 2024-02-29 06:50:09.354699Z] Finished run-tests step (success)
[task 2024-02-29T06:50:11.258Z] 06:50:09     INFO - Running post-run listener: _resource_record_post_run
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - Total resource usage - Wall time: 650s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - TinderboxPrint: I/O write bytes / time<br/>0 / 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - install-chrome-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - install - Wall time: 12s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T06:50:16.985Z] 06:50:11     INFO - run-tests - Wall time: 636s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-02-29T06:50:16.985Z] 06:50:11  WARNING - returning nonzero exit status 1
Flags: needinfo?(lissyx+mozillians)

Yes, there is still a set of error prior to my patch. That's why i'm wondering, my code only does things during generating a minidump, so if my code is at fault it means we are crashing. Is it the case on that test ?

Flags: needinfo?(lissyx+mozillians)

After investigating, looks like we are allocating memory (std::string()) and this is not allowed like that in the crash reporter code, asked for a backout

Depends on: 1883349
No longer depends on: 1883349
Component: General → mozglue
Status: NEW → RESOLVED
Closed: 8 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
See Also: → 1987807

I filed bug 1988199 for the frequent failures that are not related to bug 1987807 because I didn't find a dedicated bug. I'm not used to filing bugs for intermittent failures so feel free to fix things if something looks odd.

See Also: → 1988199
Summary: Intermittent application crashed [None] | single tracking bug → Intermittent xpcshell application crashed [None] | pid: None | single tracking bug
Status: REOPENED → RESOLVED
Closed: 8 months ago3 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: