Closed Bug 1691561 Opened 4 years ago Closed 1 year ago

Intermittent PROCESS-CRASH | None [unknown top frame] | <talos>

Categories

(Testing :: Talos, defect, P3)

Product:
Testing
Component:
Talos
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1839048

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled][comment 67][stockwell unknown])

Attachments

(3 files)

Bug 1691561 - Increase the test timeout for tabswitch. r?#perftest
(deleted), text/x-phabricator-request
Details
Bug 1691561 - Disable tabswitch talos test on macosx1014 temporarily. r?#perftest
(deleted), text/x-phabricator-request
Details
Bug 1691561 - Disable talos profiling tests. r?#perftest
(deleted), text/x-phabricator-request
Details

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

[task 2021-02-08T20:41:35.385Z] 20:41:35     INFO -  TEST-INFO | 3924: exit 0
[task 2021-02-08T20:41:35.385Z] 20:41:35     INFO -  mozcrash checking c:\users\task_1612813249\appdata\local\temp\tmphqc_lx\profile\minidumps for minidumps...
[task 2021-02-08T20:41:35.385Z] 20:41:35     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/crkIirCfQISOt7mMNs9Cww/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-02-08T20:41:36.968Z] 20:41:36     INFO -  mozcrash Copy/paste: C:/Users/task_1612813249/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1612813249\appdata\local\temp\tmphqc_lx\profile\minidumps\19d57b2a-c697-4d4e-ab5c-f67f13d086f5.dmp c:\users\task_1612813249\appdata\local\temp\tmpbirkyx
[task 2021-02-08T20:41:37.007Z] 20:41:37     INFO -  mozcrash Saved minidump as C:\Users\task_1612813249\build\blobber_upload_dir\19d57b2a-c697-4d4e-ab5c-f67f13d086f5.dmp
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  PROCESS-CRASH | pdfpaint | application crashed [unknown top frame]
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  Crash dump filename: c:\users\task_1612813249\appdata\local\temp\tmphqc_lx\profile\minidumps\19d57b2a-c697-4d4e-ab5c-f67f13d086f5.dmp
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  stderr from minidump_stackwalk:
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  2021-02-08 20:41:36: minidump_stackwalk.cc:135: ERROR: Minidump c:\users\task_1612813249\appdata\local\temp\tmphqc_lx\profile\minidumps\19d57b2a-c697-4d4e-ab5c-f67f13d086f5.dmp could not be read
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  minidump_stackwalk exited with return code 1
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -  TEST-UNEXPECTED-ERROR | pdfpaint | Found crashes after test run, terminating test
[task 2021-02-08T20:41:37.193Z] 20:41:37    ERROR -  Traceback (most recent call last):
[task 2021-02-08T20:41:37.193Z] 20:41:37     INFO -    File "C:\Users\task_1612813249\build\tests\talos\talos\run_tests.py", line 337, in run_tests
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -      talos_results.add(mytest.runTest(browser_config, test))
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -    File "C:\Users\task_1612813249\build\tests\talos\talos\ttest.py", line 65, in runTest
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -      return self._runTest(browser_config, test_config, setup)
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -    File "C:\Users\task_1612813249\build\tests\talos\talos\ttest.py", line 284, in _runTest
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -      browser_config, minidump_dir, test_config["name"]
[task 2021-02-08T20:41:37.194Z] 20:41:37     INFO -    File "C:\Users\task_1612813249\build\tests\talos\talos\ttest.py", line 49, in check_for_crashes
[task 2021-02-08T20:41:37.195Z] 20:41:37     INFO -      raise TalosCrash("Found crashes after test run, terminating test")
[task 2021-02-08T20:41:37.195Z] 20:41:37     INFO -  TalosCrash: Found crashes after test run, terminating test
[task 2021-02-08T20:41:37.195Z] 20:41:37     INFO -  TEST-INFO took 20500ms
[task 2021-02-08T20:41:37.195Z] 20:41:37     INFO -  SUITE-END | took 366s
[task 2021-02-08T20:41:37.483Z] 20:41:37    ERROR - Return code: 2
[task 2021-02-08T20:41:37.483Z] 20:41:37  WARNING - setting return code to 2
[task 2021-02-08T20:41:37.483Z] 20:41:37    ERROR - # TBPL FAILURE #```

Update:

There have been 33 failures within the last 7 days::

  • 26 failures on S X 10.14 WebRender Shippable opt
  • 2 failures on OS X 10.15 WebRender Shippable opt
  • 2 failures on Windows 10 x64 Shippable opt
  • 3 failures on Windows 10 x64 WebRender Shippable opt

Failure log: https://treeherder.mozilla.org/logviewer?job_id=337626268&repo=autoland&lineNumber=1024

[task 2021-04-24T17:33:40.473Z] 17:33:40 INFO - PROCESS-CRASH | tabswitch | application crashed [unknown top frame]
[task 2021-04-24T17:33:40.473Z] 17:33:40 INFO - Crash dump filename: /var/folders/ld/wg20dgws4d1_ts40w16hpfc0000017/T/tmprdtcwm7k/profile/minidumps/4C21C9F7-1F9A-4D71-9C91-8EB8F595C555.dmp
[task 2021-04-24T17:33:40.473Z] 17:33:40 INFO - stderr from minidump_stackwalk:
[task 2021-04-24T17:33:40.474Z] 17:33:40 INFO - 2021-04-24 17:33:40: minidump_stackwalk.cc:135: ERROR: Minidump /var/folders/ld/wg20dgws4d1_ts40w16hpfc0000017/T/tmprdtcwm7k/profile/minidumps/4C21C9F7-1F9A-4D71-9C91-8EB8F595C555.dmp could not be read
[task 2021-04-24T17:33:40.474Z] 17:33:40 INFO - minidump_stackwalk exited with return code 1
[task 2021-04-24T17:33:40.474Z] 17:33:40 INFO - TEST-UNEXPECTED-ERROR | tabswitch | Found crashes after test run, terminating test
[task 2021-04-24T17:33:40.475Z] 17:33:40 ERROR - Traceback (most recent call last):
[task 2021-04-24T17:33:40.475Z] 17:33:40 INFO - File "/Users/cltbld/tasks/task_1619284457/build/tests/talos/talos/ttest.py", line 215, in _runTest
[task 2021-04-24T17:33:40.475Z] 17:33:40 INFO - debugger_args=browser_config["debugger_args"],
[task 2021-04-24T17:33:40.475Z] 17:33:40 INFO - File "/Users/cltbld/tasks/task_1619284457/build/tests/talos/talos/talos_process.py", line 173, in run_browser
[task 2021-04-24T17:33:40.476Z] 17:33:40 INFO - raise TalosError("timeout")
[task 2021-04-24T17:33:40.476Z] 17:33:40 INFO - talos.utils.TalosError: timeout

Whiteboard: [stockwell needswork:owner]

Greg can you take a look at the failure increase here?

Flags: needinfo?(gmierz2)

Yup, I'm looking into it

This patch increases the test timeout for the tabswitch test from 10 minutes to 15 minutes.

Assignee: nobody → gmierz2
Status: NEW → ASSIGNED

This patch will take care of about 50% of the failures but there is still a high failure rate even with this change: https://treeherder.mozilla.org/jobs?repo=try&revision=d7a6b959ee4ddd58c4a2c05d08a6058568e89278&searchStr=tabswitch

Before this change this was the failure rate: https://treeherder.mozilla.org/jobs?repo=try&revision=1e89cc2fbefbbfa7699345be3a5773dab8d22061

Depends on: 1614931
Flags: needinfo?(gmierz2)
Keywords: leave-open
Pushed by gmierz2@outlook.com: https://hg.mozilla.org/integration/autoland/rev/bd61f538598b Increase the test timeout for tabswitch. r=perftest-reviewers,AlexandruIonescu

Hi Greg, seems like the patch actually increased the failure number in the last 3 days https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-05-03&endday=2021-05-10&tree=trunk&bug=1691561

Can you please take a look?

Flags: needinfo?(gmierz2)

:gsvelto, would you be able to look into this issue (bug 1614931)? I've tried to reduce the frequency by increasing the test timeout, but it's still failing a lot.

I have a try run here with some MOZ_LOG logging if it helps. I can make a try run with some other settings if that could help: https://treeherder.mozilla.org/jobs?repo=try&revision=1e89cc2fbefbbfa7699345be3a5773dab8d22061

Flags: needinfo?(gmierz2) → needinfo?(gsvelto)

I'm currently finishing a large set of patches for Windows crash reporting. macOS is my next target because besides bug 1614931 we've amassed a pretty large backlog there. I can't give you a precise timeline though because I don't know when I'll be done with Windows. Every one of these problems usually requires long investigations before I can fix them.

Flags: needinfo?(gsvelto)

Ok sounds good. I'm going to disable the tabswitch test until then.

Attachment #9221382 - Attachment description: Bug 1691561 - Disable tabswitch talos test temporarily. r?#perftest → Bug 1691561 - Disable tabswitch talos test on macosx1014 temporarily. r?#perftest
Pushed by gmierz2@outlook.com: https://hg.mozilla.org/integration/autoland/rev/bf0637965648 Disable tabswitch talos test on macosx1014 temporarily. r=perftest-reviewers,Bebe
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Whiteboard: [stockwell disabled] → [stockwell disabled], [perftest-triage]
Whiteboard: [stockwell disabled], [perftest-triage] → [stockwell disabled]

:aryx it looks like we've had an increase in the failure rate for this bug, specifically on Windows with WebRender enabled. Could you help us to narrow down when this increase started?

Flags: needinfo?(aryx.bugmail)

These hit last Thursday and Friday and got fixed by backout of bug 1701770 - the initial failures had been classified as intermittents.

Flags: needinfo?(aryx.bugmail)

Update:
There have been 32 failures within the last 7 days:
• 22 failures on Windows 10 x64 WebRender Shippable opt
• 10 failures on OS X 10.14 WebRender Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=344100105&repo=mozilla-central&lineNumber=1083

[task 2021-06-29T23:34:38.552Z] 23:34:38     INFO -  TEST-START | displaylist_mutate
[task 2021-06-29T23:34:38.552Z] 23:34:38     INFO -  Gecko profiling is enabled so talos is reducing the number of cycles, please disregard reported numbers
[task 2021-06-29T23:34:38.553Z] 23:34:38     INFO -  Initialising browser for displaylist_mutate test...
[task 2021-06-29T23:34:38.553Z] 23:34:38     INFO -  Cloning profile located at C:\Users\task_1625007944\build\tests\talos\talos\base_profile
[task 2021-06-29T23:34:38.556Z] 23:34:38     INFO -  Merging profile: C:\Users\task_1625007944\build\tests\talos\talos\profile_data\base
[task 2021-06-29T23:34:38.557Z] 23:34:38     INFO -  Merging profile: C:\Users\task_1625007944\build\tests\talos\talos\profile_data\common
[task 2021-06-29T23:34:38.564Z] 23:34:38     INFO -  Merging profile: C:\Users\task_1625007944\build\tests\talos\talos\profile_data\perf
[task 2021-06-29T23:34:38.569Z] 23:34:38     INFO -  Installing Add-ons:
[task 2021-06-29T23:34:38.570Z] 23:34:38     INFO -  ['C:\\Users\\task_1625007944\\build\\tests\\talos\\talos/talos-powers', 'C:\\Users\\task_1625007944\\build\\tests\\talos\\talos/pageloader']
[task 2021-06-29T23:34:38.594Z] 23:34:38     INFO -  Installing Webextensions:
[task 2021-06-29T23:34:38.595Z] 23:34:38     INFO -  Application command: C:\Users\task_1625007944\build\application\firefox\firefox -wait-for-browser -no-deelevate http://127.0.0.1:49864/getInfo.html --wait-for-browser -profile C:\Users\task_1625007944\AppData\Local\Temp\tmp3ss_qgj5\profile
[task 2021-06-29T23:34:38.603Z] 23:34:38     INFO -  TEST-INFO | started process 2420 (C:\Users\task_1625007944\build\application\firefox\firefox -wait-for-browser -no-deelevate http://127.0.0.1:49864/getInfo.html)
[task 2021-06-29T23:34:40.461Z] 23:34:40     INFO -  console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_1625007944\\AppData\\Local\\Temp\\tmp3ss_qgj5\\profile\\search.json.mozlz4", (void 0)))
<...>
[task 2021-06-29T23:49:47.876Z] 23:49:47     INFO -  mozcrash Saved minidump as C:\Users\task_1625007944\build\blobber_upload_dir\1d79e234-37c8-49df-bf2a-39b5b70e1f91.dmp
[task 2021-06-29T23:49:47.878Z] 23:49:47     INFO -  PROCESS-CRASH | displaylist_mutate | application crashed [unknown top frame]
[task 2021-06-29T23:49:47.879Z] 23:49:47     INFO -  Crash dump filename: C:\Users\task_1625007944\AppData\Local\Temp\tmp3ss_qgj5\profile\minidumps\1d79e234-37c8-49df-bf2a-39b5b70e1f91.dmp
[task 2021-06-29T23:49:47.879Z] 23:49:47     INFO -  Operating system: Windows NT
[task 2021-06-29T23:49:47.879Z] 23:49:47     INFO -                    10.0.17134
[task 2021-06-29T23:49:47.879Z] 23:49:47     INFO -  CPU: amd64
[task 2021-06-29T23:49:47.880Z] 23:49:47     INFO -       family 6 model 94 stepping 3
[task 2021-06-29T23:49:47.880Z] 23:49:47     INFO -       8 CPUs
[task 2021-06-29T23:49:47.880Z] 23:49:47     INFO -  GPU: UNKNOWN
[task 2021-06-29T23:49:47.881Z] 23:49:47     INFO -  No crash
[task 2021-06-29T23:49:47.881Z] 23:49:47     INFO -  Process uptime: 900 seconds
[task 2021-06-29T23:49:47.881Z] 23:49:47     INFO -  Thread 0
[task 2021-06-29T23:49:47.881Z] 23:49:47     INFO -   0  win32u.dll!NtUserMsgWaitForMultipleObjectsEx + 0x14
[task 2021-06-29T23:49:47.882Z] 23:49:47     INFO -      rax = 0x0000000000001436   rdx = 0x0000000000000000
[task 2021-06-29T23:49:47.882Z] 23:49:47     INFO -      rcx = 0x0000000000000000   rbx = 0x0000000000000000
[task 2021-06-29T23:49:47.882Z] 23:49:47     INFO -      rsi = 0x00000000ffffffff   rdi = 0x00000083485fe970
[task 2021-06-29T23:49:47.883Z] 23:49:47     INFO -      rbp = 0x00000000000db901   rsp = 0x00000083485fe8f8
[task 2021-06-29T23:49:47.883Z] 23:49:47     INFO -       r8 = 0x0000000000000018    r9 = 0xffffffffffffff01
[task 2021-06-29T23:49:47.883Z] 23:49:47     INFO -      r10 = 0x00000083485fe698   r11 = 0x0000023435dbcfec
[task 2021-06-29T23:49:47.883Z] 23:49:47     INFO -      r12 = 0x00007ffde9ee0b40   r13 = 0x00007ffde9ed84c0
[task 2021-06-29T23:49:47.884Z] 23:49:47     INFO -      r14 = 0x000000000018fbc0   r15 = 0x00007ffde9ee0200
[task 2021-06-29T23:49:47.884Z] 23:49:47     INFO -      rip = 0x00007ffde78696e4
[task 2021-06-29T23:49:47.884Z] 23:49:47     INFO -      Found by: given as instruction pointer in context
[task 2021-06-29T23:49:47.884Z] 23:49:47     INFO -   1  user32.dll!guard_dispatch_icall_nop + 0x1593d
[task 2021-06-29T23:49:47.885Z] 23:49:47     INFO -      rbx = 0x0000000000000000   rbp = 0x00000000000db901
[task 2021-06-29T23:49:47.885Z] 23:49:47     INFO -      rsp = 0x00000083485fe900   r12 = 0x00007ffde9ee0b40
[task 2021-06-29T23:49:47.885Z] 23:49:47     INFO -      r13 = 0x00007ffde9ed84c0   r14 = 0x000000000018fbc0
[task 2021-06-29T23:49:47.885Z] 23:49:47     INFO -      r15 = 0x00007ffde9ee0200   rip = 0x00007ffde9ee029d
[task 2021-06-29T23:49:47.885Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.886Z] 23:49:47     INFO -   2  xul.dll!static mozilla::widget::WinUtils::WaitForMessage(unsigned long) [WinUtils.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 789 + 0x1d]
[task 2021-06-29T23:49:47.886Z] 23:49:47     INFO -      rsp = 0x00000083485fe940   rip = 0x00007ffda9df23d9
[task 2021-06-29T23:49:47.886Z] 23:49:47     INFO -      Found by: stack scanning
[task 2021-06-29T23:49:47.887Z] 23:49:47     INFO -   3  xul.dll!nsAppShell::ProcessNextNativeEvent(bool) [nsAppShell.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 745 + 0xa]
[task 2021-06-29T23:49:47.887Z] 23:49:47     INFO -      rsp = 0x00000083485fea10   rip = 0x00007ffdab327805
[task 2021-06-29T23:49:47.887Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.887Z] 23:49:47     INFO -   4  xul.dll!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 259 + 0x42]
[task 2021-06-29T23:49:47.888Z] 23:49:47     INFO -      rsp = 0x00000083485feb00   rip = 0x00007ffdab326c1c
[task 2021-06-29T23:49:47.888Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.888Z] 23:49:47     INFO -   5  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 1068 + 0x52]
[task 2021-06-29T23:49:47.888Z] 23:49:47     INFO -      rsp = 0x00000083485fec50   rip = 0x00007ffdab168c09
[task 2021-06-29T23:49:47.888Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.889Z] 23:49:47     INFO -   6  xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [MessagePump.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 107 + 0x2c]
[task 2021-06-29T23:49:47.889Z] 23:49:47     INFO -      rsp = 0x00000083485fefe0   rip = 0x00007ffdab4fb3d6
[task 2021-06-29T23:49:47.889Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.890Z] 23:49:47     INFO -   7  xul.dll!MessageLoop::RunHandler() [message_loop.cc:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 324 + 0x16]
[task 2021-06-29T23:49:47.890Z] 23:49:47     INFO -      rsp = 0x00000083485ff100   rip = 0x00007ffdaa49af7f
[task 2021-06-29T23:49:47.890Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.890Z] 23:49:47     INFO -   8  xul.dll!MessageLoop::Run() [message_loop.cc:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 306 + 0x5]
[task 2021-06-29T23:49:47.891Z] 23:49:47     INFO -      rsp = 0x00000083485ff150   rip = 0x00007ffda9a98f2e
[task 2021-06-29T23:49:47.891Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.891Z] 23:49:47     INFO -   9  xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 137 + 0xd]
[task 2021-06-29T23:49:47.891Z] 23:49:47     INFO -      rsp = 0x00000083485ff1b0   rip = 0x00007ffda9c215d8
[task 2021-06-29T23:49:47.892Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.892Z] 23:49:47     INFO -  10  xul.dll!nsAppShell::Run() [nsAppShell.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 603 + 0x8]
[task 2021-06-29T23:49:47.892Z] 23:49:47     INFO -      rsp = 0x00000083485ff1f0   rip = 0x00007ffda9c2040f
[task 2021-06-29T23:49:47.892Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.893Z] 23:49:47     INFO -  11  xul.dll!nsAppStartup::Run() [nsAppStartup.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 273 + 0xd]
[task 2021-06-29T23:49:47.893Z] 23:49:47     INFO -      rsp = 0x00000083485ff360   rip = 0x00007ffdade830da
[task 2021-06-29T23:49:47.893Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.894Z] 23:49:47     INFO -  12  xul.dll!XREMain::XRE_mainRun() [nsAppRunner.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 5254 + 0xd]
[task 2021-06-29T23:49:47.894Z] 23:49:47     INFO -      rsp = 0x00000083485ff3b0   rip = 0x00007ffdadef16fb
[task 2021-06-29T23:49:47.894Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.894Z] 23:49:47     INFO -  13  xul.dll!XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 5452 + 0x8]
[task 2021-06-29T23:49:47.895Z] 23:49:47     INFO -      rsp = 0x00000083485ff6f0   rip = 0x00007ffdadef23c3
[task 2021-06-29T23:49:47.895Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.895Z] 23:49:47     INFO -  14  xul.dll!XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 5511 + 0x10]
[task 2021-06-29T23:49:47.895Z] 23:49:47     INFO -      rsp = 0x00000083485ff7b0   rip = 0x00007ffdab9ffd63
[task 2021-06-29T23:49:47.896Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.896Z] 23:49:47     INFO -  15  firefox.exe!wmain(int, wchar_t**) [nsWindowsWMain.cpp:2b98f2b592f064c7bba1dfdcd6dafb1cde3cde4a : 138 + 0x1e0]
[task 2021-06-29T23:49:47.896Z] 23:49:47     INFO -      rsp = 0x00000083485ff900   rip = 0x00007ff769caa55d
[task 2021-06-29T23:49:47.896Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.897Z] 23:49:47     INFO -  16  firefox.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x22]
[task 2021-06-29T23:49:47.897Z] 23:49:47     INFO -      rsp = 0x00000083485ffb20   rip = 0x00007ff769cbd648
[task 2021-06-29T23:49:47.897Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.897Z] 23:49:47     INFO -  17  kernel32.dll!guard_dispatch_icall_nop + 0x86d4
[task 2021-06-29T23:49:47.898Z] 23:49:47     INFO -      rsp = 0x00000083485ffb60   rip = 0x00007ffde9c83034
[task 2021-06-29T23:49:47.898Z] 23:49:47     INFO -      Found by: call frame info
[task 2021-06-29T23:49:47.898Z] 23:49:47     INFO -  18  ntdll.dll!guard_dispatch_icall_nop + 0x66b01
[task 2021-06-29T23:49:47.898Z] 23:49:47     INFO -      rsp = 0x00000083485ffb90   rip = 0x00007ffdea7b1461
[task 2021-06-29T23:49:47.898Z] 23:49:47     INFO -      Found by: stack scanning
Whiteboard: [stockwell disabled] → [stockwell disabled] [stockwell needswork:owner]
Pushed by archaeopteryx@coole-files.de: https://hg.mozilla.org/integration/autoland/rev/06974bb3d3b6 Disable talos profiling tests. r=perftest-reviewers,Bebe

It looks like we have an increase in crashes for glvideo and glterrain tests. (https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-08-25&endday=2021-09-01&tree=all&bug=1691561)
Can you take a look at this? :jgilbert

Flags: needinfo?(jgilbert)

It's starting the browser, hitting timeout after 10m of apparently nothing, and the crashdump shows us waiting for events in the main event loop:

[task 2021-09-15T19:24:18.984Z] 19:24:18     INFO -  TEST-INFO | started process 5868 (C:\Users\task_1631718858\build\application\firefox\firefox -wait-for-browser -no-deelevate -profile C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile)
[task 2021-09-15T19:24:24.938Z] 19:24:24     INFO -  PID 5868 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_1631718858\\AppData\\Local\\Temp\\tmphn6c9hwt\\profile\\search.json.mozlz4", (void 0), 215))
[task 2021-09-15T19:34:18.983Z] 19:34:18     INFO -  Timeout waiting for test completion; killing browser...
[task 2021-09-15T19:34:18.986Z] 19:34:18     INFO -  Launcher process psutil.Process(pid=5868, name='firefox.exe', started='19:24:18') detected. Killing parent process psutil.Process(pid=6992, name='firefox.exe', started='19:24:19') instead.
[task 2021-09-15T19:34:18.986Z] 19:34:18     INFO -  Killing psutil.Process(pid=6992, name='firefox.exe', started='19:24:19') and writing a minidump file
[task 2021-09-15T19:34:18.986Z] 19:34:18     INFO -  mozcrash Writing a dump to C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile\minidumps\e09bdd8a-ef5c-4dbd-96c5-924862cc49fb.dmp for [6992]
[task 2021-09-15T19:34:20.956Z] 19:34:20     INFO -  mozcrash checking C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile\minidumps for minidumps...
[task 2021-09-15T19:34:20.956Z] 19:34:20     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/T-wF8bZTTS288yDnoXC1hg/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-09-15T19:34:25.178Z] 19:34:25     INFO -  mozcrash Copy/paste: C:/Users/task_1631718858/fetches\minidump_stackwalk\minidump_stackwalk.exe C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile\minidumps\e09bdd8a-ef5c-4dbd-96c5-924862cc49fb.dmp C:\Users\task_1631718858\AppData\Local\Temp\tmpvu4ghf2l
[task 2021-09-15T19:34:34.234Z] 19:34:34     INFO -  mozcrash Saved minidump as C:\Users\task_1631718858\build\blobber_upload_dir\e09bdd8a-ef5c-4dbd-96c5-924862cc49fb.dmp
[task 2021-09-15T19:34:34.236Z] 19:34:34     INFO -  PROCESS-CRASH | glterrain | application crashed [unknown top frame]
[task 2021-09-15T19:34:34.237Z] 19:34:34     INFO -  Crash dump filename: C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile\minidumps\e09bdd8a-ef5c-4dbd-96c5-924862cc49fb.dmp
[task 2021-09-15T19:34:34.237Z] 19:34:34     INFO -  Operating system: Windows NT
[task 2021-09-15T19:34:34.238Z] 19:34:34     INFO -                    10.0.17134
[task 2021-09-15T19:34:34.238Z] 19:34:34     INFO -  CPU: amd64
[task 2021-09-15T19:34:34.238Z] 19:34:34     INFO -       family 6 model 142 stepping 9
[task 2021-09-15T19:34:34.238Z] 19:34:34     INFO -       4 CPUs
[task 2021-09-15T19:34:34.239Z] 19:34:34     INFO -  GPU: UNKNOWN
[task 2021-09-15T19:34:34.239Z] 19:34:34     INFO -  No crash
[task 2021-09-15T19:34:34.239Z] 19:34:34     INFO -  Process uptime: 601 seconds
[task 2021-09-15T19:34:34.240Z] 19:34:34     INFO -  Thread 0 tid 6796 - GeckoMain
[task 2021-09-15T19:34:34.240Z] 19:34:34     INFO -   0  win32u.dll!NtUserMsgWaitForMultipleObjectsEx + 0x14
[task 2021-09-15T19:34:34.240Z] 19:34:34     INFO -      rax = 0x0000000000001436   rdx = 0x0000000000000000
[task 2021-09-15T19:34:34.241Z] 19:34:34     INFO -      rcx = 0x0000000000000000   rbx = 0x0000000000000000
[task 2021-09-15T19:34:34.241Z] 19:34:34     INFO -      rsi = 0x00000000ffffffff   rdi = 0x000000279a1fe9b0
[task 2021-09-15T19:34:34.241Z] 19:34:34     INFO -      rbp = 0x0000000000091701   rsp = 0x000000279a1fe938
[task 2021-09-15T19:34:34.242Z] 19:34:34     INFO -       r8 = 0x000000279a1fde81    r9 = 0xfffffff66b195bfa
[task 2021-09-15T19:34:34.242Z] 19:34:34     INFO -      r10 = 0x00000fff5ec20b9a   r11 = 0x0000000004000000
[task 2021-09-15T19:34:34.242Z] 19:34:34     INFO -      r12 = 0x00007ffb09310550   r13 = 0x00007ffb09308020
[task 2021-09-15T19:34:34.243Z] 19:34:34     INFO -      r14 = 0x00000000008a50a1   r15 = 0x00007ffb0930fc10
[task 2021-09-15T19:34:34.243Z] 19:34:34     INFO -      rip = 0x00007ffb08c596e4
[task 2021-09-15T19:34:34.243Z] 19:34:34     INFO -      Found by: given as instruction pointer in context
[task 2021-09-15T19:34:34.244Z] 19:34:34     INFO -   1  user32.dll!guard_dispatch_icall_nop + 0x1534d
[task 2021-09-15T19:34:34.244Z] 19:34:34     INFO -      rbx = 0x0000000000000000   rbp = 0x0000000000091701
[task 2021-09-15T19:34:34.244Z] 19:34:34     INFO -      rsp = 0x000000279a1fe940   r12 = 0x00007ffb09310550
[task 2021-09-15T19:34:34.244Z] 19:34:34     INFO -      r13 = 0x00007ffb09308020   r14 = 0x00000000008a50a1
[task 2021-09-15T19:34:34.245Z] 19:34:34     INFO -      r15 = 0x00007ffb0930fc10   rip = 0x00007ffb0930fcad
[task 2021-09-15T19:34:34.245Z] 19:34:34     INFO -      Found by: call frame info
[task 2021-09-15T19:34:34.245Z] 19:34:34     INFO -   2  xul.dll + 0x1a96e20
[task 2021-09-15T19:34:34.246Z] 19:34:34     INFO -      rsp = 0x000000279a1fe948   rip = 0x00007ffad70d6e20
[task 2021-09-15T19:34:34.246Z] 19:34:34     INFO -      Found by: stack scanning
[task 2021-09-15T19:34:34.246Z] 19:34:34     INFO -   3  xul.dll!static mozilla::widget::WinUtils::WaitForMessage(unsigned long) [WinUtils.cpp:407b3b1993822c2fd6baed5b68534951d81650df : 831 + 0x1d]
[task 2021-09-15T19:34:34.247Z] 19:34:34     INFO -      rsp = 0x000000279a1fe980   rip = 0x00007ffad5993699
[task 2021-09-15T19:34:34.247Z] 19:34:34     INFO -      Found by: stack scanning

Let me re-run the job to see what a good log looks like.

Flags: needinfo?(jgilbert)

https://treeherder.mozilla.org/jobs?repo=autoland&revision=407b3b1993822c2fd6baed5b68534951d81650df&selectedTaskRun=Q7AlnKQ0Qainn87x3CPk_g.0

[task 2021-09-15T19:24:18.984Z] 19:24:18     INFO -  TEST-INFO | started process 5868 (C:\Users\task_1631718858\build\application\firefox\firefox -wait-for-browser -no-deelevate -profile C:\Users\task_1631718858\AppData\Local\Temp\tmphn6c9hwt\profile)
[task 2021-09-15T19:24:24.938Z] 19:24:24     INFO -  PID 5868 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_1631718858\\AppData\\Local\\Temp\\tmphn6c9hwt\\profile\\search.json.mozlz4", (void 0), 215))
[task 2021-09-15T19:34:18.983Z] 19:34:18     INFO -  Timeout waiting for test completion; killing browser...

https://treeherder.mozilla.org/jobs?repo=autoland&revision=d1e96fb23d43a891d3186d8ac5c8cbfc73ec6306&selectedTaskRun=EX8vqZxpQHiJKR5pJlHc3g.0

[task 2021-09-07T07:53:30.770Z] 07:53:30     INFO -  TEST-INFO | started process 6876 (C:\Users\task_1630971846\build\application\firefox\firefox -wait-for-browser -no-deelevate -profile C:\Users\task_1630971846\AppData\Local\Temp\tmpn_knkt48\profile)
[task 2021-09-07T08:02:01.940Z] 08:02:01     INFO -  PID 6876 | 1631001721940	addons.xpi	ERROR	System addon update list error Error: Failed downloading XML, status: 0, reason: error
[task 2021-09-07T08:03:30.758Z] 08:03:30     INFO -  Timeout waiting for test completion; killing browser...

https://treeherder.mozilla.org/jobs?repo=autoland&revision=4e61dfde0ad601e48df245bdaf93f3d19b91d845&selectedTaskRun=PN_tVrdFRRWBRN7zIIYNZA.0

[task 2021-09-12T23:21:04.768Z] 23:21:04     INFO -  TEST-INFO | started process 8184 (C:\Users\task_1631479147\build\application\firefox\firefox -wait-for-browser -no-deelevate -profile C:\Users\task_1631479147\AppData\Local\Temp\tmpd3b6agly\profile)
[task 2021-09-12T23:21:05.508Z] 23:21:05     INFO -  PID 8184 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_1631479147\\AppData\\Local\\Temp\\tmpd3b6agly\\profile\\search.json.mozlz4", (void 0)))
[task 2021-09-12T23:21:24.023Z] 23:21:24     INFO -  PID 8184 | Cycle 1(1): loaded http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000 (next: http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000)
[task 2021-09-12T23:21:40.487Z] 23:21:40     INFO -  PID 8184 | Cycle 1(2): loaded http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000 (next: http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000)
[task 2021-09-12T23:21:56.535Z] 23:21:56     INFO -  PID 8184 | Cycle 1(3): loaded http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000 (next: http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000)
[task 2021-09-12T23:22:12.634Z] 23:22:12     INFO -  PID 8184 | Cycle 1(4): loaded http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000 (next: http://127.0.0.1:49841/tests/webkit/PerformanceTests/MotionMark/developer.html?test-interval=15&display=minimal&tiles=big&controller=fixed&frame-rate=50&kalman-process-error=1&kalman-measurement-error=4&time-measurement=performance&suite-name=3DGraphics&test-name=WebGL&complexity=30000)
[task 2021-09-12T23:31:04.777Z] 23:31:04     INFO -  Timeout waiting for test completion; killing browser...

There's no definitive difference between good and bad runs that I can see. Sometimes runs can get started and then fail, but other times they just never start properly.
I suspect either a race condition with hooking the browser up to its testrunner, or an issue with something else running on the machines. (Remember when we would get failures when the screensaver would activate?)
I don't think there's much I can do here.

Whiteboard: [stockwell disabled] [stockwell needswork:owner] → [stockwell disabled] [stockwell needswork:owner][comment 67]

This test has been failing for some time now
Is the reference hardware good still and if not should we remove it?

Flags: needinfo?(jmaher)
Flags: needinfo?(dave.hunt)

We appear to be only running glterrain, glvideo, and motionmark_webgl against the reference hardware. Whilst it's possible that these tests are detecting unique regressions on this hardware I think it's highly unlikely. I also don't believe these results are being monitored elsewhere. I propose disabling these tests, but continuing to allow them to run via try. What do you think jmaher?

Flags: needinfo?(dave.hunt)

:davehunt, if we don't think we are finding good failures due to the other hardware finding issues or not running proper tests, we should get rid of this test pool. I don't see any value in having try server for these tests if we are not running them in production anywhere. Getting rid of the test pool simplifies a lot of things. Maybe we need to upgrade the pool to a more reliable set of machines?

Flags: needinfo?(jmaher)

(In reply to Joel Maher ( :jmaher ) (UTC -0800) from comment #81)

:davehunt, if we don't think we are finding good failures due to the other hardware finding issues or not running proper tests, we should get rid of this test pool. I don't see any value in having try server for these tests if we are not running them in production anywhere. Getting rid of the test pool simplifies a lot of things. Maybe we need to upgrade the pool to a more reliable set of machines?

After discussion with :plawless and :bas we're in agreement that we should retire the windows10-64-ref-hw-2017 hardware pool. We're planning to identify a replacement reference device, but we can remove the pool with immediate effect. :jmaher do you need me to file a bug for this, or can you take care of it?

Flags: needinfo?(jmaher)

thanks for looking into this- file a bug and I will take over- this will simplify a few things and I will expect to hear back in the next couple of months for what lower end hardware we want to replace this with!

Flags: needinfo?(jmaher)

Very frequent failures appeared on sessionrestore: https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=os%2Cx%2C10.15%2Cwebrender%2Cshippable%2Copt%2Ctalos%2Cperformance%2Ctests%2Cwith%2Cfission%2Cenabled%2Ctest-macosx1015-64-shippable-qr%2Fopt-talos-other-fis-e10s%2Co&tochange=42a64fe0c062cd296da3ab22a14f938fd2663caa&fromchange=c858714b247620ccd0de475d4cce021b081be5d4&group_state=expanded

[task 2021-12-02T01:01:04.452Z] 01:01:04     INFO -  PROCESS-CRASH | sessionrestore_no_auto_restore | application crashed [unknown top frame]
[task 2021-12-02T01:01:04.452Z] 01:01:04     INFO -  Crash dump filename: /var/folders/km/vp1xqc9565l_rzflvf70skjc000014/T/tmpk55ztlnw/profile/minidumps/092D9113-0A9A-47F5-9D11-AC84ECD0953D.dmp
[task 2021-12-02T01:01:04.453Z] 01:01:04     INFO -  stderr from minidump_stackwalk:
[task 2021-12-02T01:01:04.453Z] 01:01:04     INFO -  [ERROR] Error reading dump
[task 2021-12-02T01:01:04.453Z] 01:01:04     INFO -  minidump_stackwalk exited with return code 1
[task 2021-12-02T01:01:04.453Z] 01:01:04     INFO -  TEST-UNEXPECTED-ERROR | sessionrestore_no_auto_restore | Found crashes after test run, terminating test
[task 2021-12-02T01:01:04.454Z] 01:01:04    ERROR -  Traceback (most recent call last):
[task 2021-12-02T01:01:04.454Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/ttest.py", line 215, in _runTest
[task 2021-12-02T01:01:04.454Z] 01:01:04     INFO -      debugger_args=browser_config["debugger_args"],
[task 2021-12-02T01:01:04.454Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/talos_process.py", line 173, in run_browser
[task 2021-12-02T01:01:04.454Z] 01:01:04     INFO -      raise TalosError("timeout")
[task 2021-12-02T01:01:04.455Z] 01:01:04     INFO -  talos.utils.TalosError: timeout
[task 2021-12-02T01:01:04.455Z] 01:01:04     INFO -  During handling of the above exception, another exception occurred:
[task 2021-12-02T01:01:04.455Z] 01:01:04    ERROR -  Traceback (most recent call last):
[task 2021-12-02T01:01:04.455Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/run_tests.py", line 336, in run_tests
[task 2021-12-02T01:01:04.455Z] 01:01:04     INFO -      talos_results.add(mytest.runTest(browser_config, test))
[task 2021-12-02T01:01:04.456Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/ttest.py", line 65, in runTest
[task 2021-12-02T01:01:04.456Z] 01:01:04     INFO -      return self._runTest(browser_config, test_config, setup)
[task 2021-12-02T01:01:04.456Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/ttest.py", line 219, in _runTest
[task 2021-12-02T01:01:04.456Z] 01:01:04     INFO -      browser_config, minidump_dir, test_config["name"]
[task 2021-12-02T01:01:04.456Z] 01:01:04     INFO -    File "/opt/worker/tasks/task_163840287248756/build/tests/talos/talos/ttest.py", line 49, in check_for_crashes
[task 2021-12-02T01:01:04.457Z] 01:01:04     INFO -      raise TalosCrash("Found crashes after test run, terminating test")
[task 2021-12-02T01:01:04.457Z] 01:01:04     INFO -  talos.utils.TalosCrash: Found crashes after test run, terminating test
[task 2021-12-02T01:01:04.457Z] 01:01:04     INFO -  TEST-INFO took 311295ms

:nataliacs, could you bisect this failure to see where it started on autoland? Given the high increase in failure rates, I'm hoping that we can find a culprit commit.

Flags: needinfo?(ncsoregi)

Thanks for the backfill!

:gijs, is it possible that your patch caused this regression? https://hg.mozilla.org/integration/autoland/rev/f54285c09367

After your patch, these warnings started appearing in the logs:

[task 2021-12-02T17:34:36.248Z] 17:34:36    ERROR -  PID 1767 | WARNING: TypeError: can't access property "shutdown", Barriers is undefined
[task 2021-12-02T17:34:36.249Z] 17:34:36     INFO -  PID 1767 | WARNING: @resource://gre/modules/osfile/osfile_async_front.jsm:635:5
[task 2021-12-02T17:34:36.249Z] 17:34:36     INFO -  PID 1767 | trigger@resource://gre/modules/AsyncShutdown.jsm:747:23
[task 2021-12-02T17:34:36.249Z] 17:34:36     INFO -  PID 1767 | _wait@resource://gre/modules/AsyncShutdown.jsm:899:15
[task 2021-12-02T17:34:36.249Z] 17:34:36     INFO -  PID 1767 | wait@resource://gre/modules/AsyncShutdown.jsm:880:34
[task 2021-12-02T17:34:36.250Z] 17:34:36     INFO -  PID 1767 | observe@resource://gre/modules/AsyncShutdown.jsm:557:10
[task 2021-12-02T17:34:36.250Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.250Z] 17:34:36     INFO -  PID 1767 | WARNING: A blocker encountered an error while we were waiting.
[task 2021-12-02T17:34:36.251Z] 17:34:36     INFO -  PID 1767 |           Blocker:  OS.File: flush pending requests, warn about unclosed files, shut down service.
[task 2021-12-02T17:34:36.251Z] 17:34:36     INFO -  PID 1767 |           Phase: xpcom-will-shutdown
[task 2021-12-02T17:34:36.251Z] 17:34:36    ERROR -  PID 1767 |           State: Error getting state: TypeError: can't access property "getDetails", Barriers is undefined at @resource://gre/modules/osfile/osfile_async_front.jsm:641:19
[task 2021-12-02T17:34:36.251Z] 17:34:36     INFO -  PID 1767 | safeGetState@resource://gre/modules/AsyncShutdown.jsm:257:17
[task 2021-12-02T17:34:36.251Z] 17:34:36     INFO -  PID 1767 | Barrier/addBlocker/promise<@resource://gre/modules/AsyncShutdown.jsm:766:20
[task 2021-12-02T17:34:36.252Z] 17:34:36     INFO -  PID 1767 | observe@resource://gre/modules/AsyncShutdown.jsm:575:16
[task 2021-12-02T17:34:36.252Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.252Z] 17:34:36    ERROR -  PID 1767 | WARNING: TypeError: can't access property "shutdown", Barriers is undefined
[task 2021-12-02T17:34:36.252Z] 17:34:36     INFO -  PID 1767 | WARNING: @resource://gre/modules/osfile/osfile_async_front.jsm:635:5
[task 2021-12-02T17:34:36.252Z] 17:34:36     INFO -  PID 1767 | trigger@resource://gre/modules/AsyncShutdown.jsm:747:23
[task 2021-12-02T17:34:36.253Z] 17:34:36     INFO -  PID 1767 | _wait@resource://gre/modules/AsyncShutdown.jsm:899:15
[task 2021-12-02T17:34:36.253Z] 17:34:36     INFO -  PID 1767 | wait@resource://gre/modules/AsyncShutdown.jsm:880:34
[task 2021-12-02T17:34:36.253Z] 17:34:36     INFO -  PID 1767 | observe@resource://gre/modules/AsyncShutdown.jsm:557:10
[task 2021-12-02T17:34:36.253Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.254Z] 17:34:36     INFO -  PID 1767 | WARNING: A blocker encountered an error while we were waiting.
[task 2021-12-02T17:34:36.254Z] 17:34:36     INFO -  PID 1767 |           Blocker:  OS.File: flush pending requests, warn about unclosed files, shut down service.
[task 2021-12-02T17:34:36.254Z] 17:34:36     INFO -  PID 1767 |           Phase: xpcom-will-shutdown
[task 2021-12-02T17:34:36.254Z] 17:34:36    ERROR -  PID 1767 |           State: Error getting state: TypeError: can't access property "getDetails", Barriers is undefined at @resource://gre/modules/osfile/osfile_async_front.jsm:641:19
[task 2021-12-02T17:34:36.255Z] 17:34:36     INFO -  PID 1767 | safeGetState@resource://gre/modules/AsyncShutdown.jsm:257:17
[task 2021-12-02T17:34:36.255Z] 17:34:36     INFO -  PID 1767 | Barrier/addBlocker/promise<@resource://gre/modules/AsyncShutdown.jsm:766:20
[task 2021-12-02T17:34:36.255Z] 17:34:36     INFO -  PID 1767 | observe@resource://gre/modules/AsyncShutdown.jsm:575:16
[task 2021-12-02T17:34:36.255Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.255Z] 17:34:36    ERROR -  PID 1767 | WARNING: TypeError: can't access property "shutdown", Barriers is undefined
[task 2021-12-02T17:34:36.256Z] 17:34:36     INFO -  PID 1767 | WARNING: @resource://gre/modules/osfile/osfile_async_front.jsm:635:5
[task 2021-12-02T17:34:36.256Z] 17:34:36     INFO -  PID 1767 | trigger@resource://gre/modules/AsyncShutdown.jsm:747:23
[task 2021-12-02T17:34:36.256Z] 17:34:36     INFO -  PID 1767 | _wait@resource://gre/modules/AsyncShutdown.jsm:899:15
[task 2021-12-02T17:34:36.256Z] 17:34:36     INFO -  PID 1767 | wait@resource://gre/modules/AsyncShutdown.jsm:880:34
[task 2021-12-02T17:34:36.257Z] 17:34:36     INFO -  PID 1767 | observe@resource://gre/modules/AsyncShutdown.jsm:557:10
[task 2021-12-02T17:34:36.257Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.259Z] 17:34:36     INFO -  PID 1767 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: region-update-timer
[task 2021-12-02T17:34:36.259Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.259Z] 17:34:36     INFO -  PID 1767 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-12-02T17:34:36.259Z] 17:34:36     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.437Z] 17:34:36     INFO -  PID 1767 | [2021-12-02T17:34:36Z ERROR xulstore::persist] removeDocument error: unavailable
[task 2021-12-02T17:34:36.458Z] 17:34:36     INFO -  TEST-INFO | 1767: exit 0

Here's a link to the try push: https://treeherder.mozilla.org/jobs?repo=autoland&selectedTaskRun=ETwue0eKQj-TuK4AauUxFA.0&searchStr=talos%2Cother%2Cmac&revision=f54285c09367394da49160ee8970f4e1b66c5f5b

And a link to the logs for one of the failures: https://firefoxci.taskcluster-artifacts.net/ETwue0eKQj-TuK4AauUxFA/0/public/logs/live_backing.log

I see those warnings in the passing tasks too but they only started appearing on the try push with your patch in it.

Flags: needinfo?(gmierz2) → needinfo?(gijskruitbosch+bugs)

Given that the errors happen on successful runs too it's unclear to me how they're related. Mark recently ran into similar-ish issues and filed bug 1740261 for other unrelated errors. I'll file a separate bug but I would be surprised if that resolved the issue.

The other part to that is that the run with the errors actually succeeds and shuts down normally, but then the next run, this happens:

[task 2021-12-02T17:34:36.842Z] 17:34:36     INFO -  TEST-INFO | started process 1770 (/opt/worker/tasks/task_163846549615689/build/application/Firefox Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile about:home)
[task 2021-12-02T17:34:37.854Z] 17:34:37     INFO -  PID 1770 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile/search.json.mozlz4", (void 0)))
[task 2021-12-02T17:35:07.168Z] 17:35:07     INFO -  PID 1770 | 2021-12-02 17:35:07.167 firefox[1770:32894] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
[task 2021-12-02T17:39:36.984Z] 17:39:36     INFO -  Timeout waiting for test completion; killing browser...
[task 2021-12-02T17:39:36.984Z] 17:39:36     INFO -  Killing psutil.Process(pid=1770, name='firefox', status='running', started='17:34:36') and writing a minidump file
[task 2021-12-02T17:39:36.987Z] 17:39:36     INFO -  Terminating psutil.Process(pid=1770, name='firefox', status='running', started='17:34:36')
[task 2021-12-02T17:39:37.003Z] 17:39:37     INFO -  PID 1770 | Exiting due to channel error.
[task 2021-12-02T17:39:37.003Z] 17:39:37     INFO -  PID 1770 | Exiting due to channel error.
[task 2021-12-02T17:39:37.003Z] 17:39:37     INFO -  PID 1770 | Exiting due to channel error.
[task 2021-12-02T17:39:37.003Z] 17:39:37     INFO -  PID 1770 | Exiting due to channel error.
[task 2021-12-02T17:39:37.004Z] 17:39:37     INFO -  PID 1770 | Exiting due to channel error.
[task 2021-12-02T17:39:37.023Z] 17:39:37     INFO -  mozcrash checking /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile/minidumps for minidumps...
[task 2021-12-02T17:39:37.024Z] 17:39:37     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/YvOruQlSQ7eXrlhEBnpfpw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-12-02T17:39:40.623Z] 17:39:40     INFO -  mozcrash Copy/paste: /opt/worker/tasks/task_163846549615689/fetches/minidump_stackwalk/minidump_stackwalk --human /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile/minidumps/440F1A69-D547-45AE-8A57-1F320A74F813.dmp /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp6k7vvbja --symbols-url=https://symbols.mozilla.org/
[task 2021-12-02T17:39:40.630Z] 17:39:40     INFO -  mozcrash Saved minidump as /opt/worker/tasks/task_163846549615689/build/blobber_upload_dir/440F1A69-D547-45AE-8A57-1F320A74F813.dmp
[task 2021-12-02T17:39:40.734Z] 17:39:40     INFO -  PROCESS-CRASH | sessionrestore_no_auto_restore | application crashed [unknown top frame]
[task 2021-12-02T17:39:40.735Z] 17:39:40     INFO -  Crash dump filename: /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile/minidumps/440F1A69-D547-45AE-8A57-1F320A74F813.dmp
[task 2021-12-02T17:39:40.735Z] 17:39:40     INFO -  stderr from minidump_stackwalk:
[task 2021-12-02T17:39:40.735Z] 17:39:40     INFO -  [ERROR] Error reading dump
[task 2021-12-02T17:39:40.735Z] 17:39:40     INFO -  minidump_stackwalk exited with return code 1
[task 2021-12-02T17:39:40.735Z] 17:39:40     INFO -  TEST-UNEXPECTED-ERROR | sessionrestore_no_auto_restore | Found crashes after test run, terminating test
[task 2021-12-02T17:39:40.736Z] 17:39:40    ERROR -  Traceback (most recent call last):
[task 2021-12-02T17:39:40.736Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/ttest.py", line 215, in _runTest
[task 2021-12-02T17:39:40.736Z] 17:39:40     INFO -      debugger_args=browser_config["debugger_args"],
[task 2021-12-02T17:39:40.736Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/talos_process.py", line 173, in run_browser
[task 2021-12-02T17:39:40.737Z] 17:39:40     INFO -      raise TalosError("timeout")
[task 2021-12-02T17:39:40.737Z] 17:39:40     INFO -  talos.utils.TalosError: timeout
[task 2021-12-02T17:39:40.737Z] 17:39:40     INFO -  During handling of the above exception, another exception occurred:
[task 2021-12-02T17:39:40.737Z] 17:39:40    ERROR -  Traceback (most recent call last):
[task 2021-12-02T17:39:40.737Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/run_tests.py", line 336, in run_tests
[task 2021-12-02T17:39:40.738Z] 17:39:40     INFO -      talos_results.add(mytest.runTest(browser_config, test))
[task 2021-12-02T17:39:40.738Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/ttest.py", line 65, in runTest
[task 2021-12-02T17:39:40.738Z] 17:39:40     INFO -      return self._runTest(browser_config, test_config, setup)
[task 2021-12-02T17:39:40.738Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/ttest.py", line 219, in _runTest
[task 2021-12-02T17:39:40.739Z] 17:39:40     INFO -      browser_config, minidump_dir, test_config["name"]
[task 2021-12-02T17:39:40.739Z] 17:39:40     INFO -    File "/opt/worker/tasks/task_163846549615689/build/tests/talos/talos/ttest.py", line 49, in check_for_crashes
[task 2021-12-02T17:39:40.739Z] 17:39:40     INFO -      raise TalosCrash("Found crashes after test run, terminating test")
[task 2021-12-02T17:39:40.739Z] 17:39:40     INFO -  talos.utils.TalosCrash: Found crashes after test run, terminating test
[task 2021-12-02T17:39:40.739Z] 17:39:40     INFO -  TEST-INFO took 323468ms

So this is actually a startup issue, but it's not clear to me what causes it or how to investigate further. The fact that the crash dump is unreadable (I guess that's bug 1614931, Gabriele?) doesn't help. Basically, this reproduces only sporadically on try, but there's no trace of what the state of the process is when it fails to start or how that relates to any of these changes, so it's almost impossible to say why something broke here. Barret, I don't suppose you have any ideas? :-\

Also, Mark, what's up with these errors, even on runs 9/10 of the test:

[task 2021-12-02T17:34:35.944Z] 17:34:35     INFO -  PID 1767 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /var/folders/ss/fzy6v4s53sz2tpsl2fcw0r9w000014/T/tmp90urp61t/profile/search.json.mozlz4", (void 0)))
[task 2021-12-02T17:34:35.988Z] 17:34:35     INFO -  PID 1767 | console.error: "Profiler could not init with object: {}"
[task 2021-12-02T17:34:35.988Z] 17:34:35     INFO -  PID 1767 | __start_report998__end_report
[task 2021-12-02T17:34:35.988Z] 17:34:35     INFO -  PID 1767 |
[task 2021-12-02T17:34:35.988Z] 17:34:35     INFO -  PID 1767 | __startTimestamp721.519317__endTimestamp
[task 2021-12-02T17:34:35.988Z] 17:34:35     INFO -  PID 1767 |
[task 2021-12-02T17:34:36.201Z] 17:34:36     INFO -  PID 1767 | console.error: "Could not load engine ddg@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: callAddonListeners :: line 1580\"  data: no]"
[task 2021-12-02T17:34:36.202Z] 17:34:36     INFO -  PID 1767 | console.error: "Could not load engine ebay@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2543\"  data: no]"
[task 2021-12-02T17:34:36.202Z] 17:34:36     INFO -  PID 1767 | console.warn: SearchService: "_init: abandoning init due to shutting down"

I guess we should make the test wait for startup to have finished before shutting down, to guarantee more reasonable behaviour?

Flags: needinfo?(standard8)
Flags: needinfo?(gsvelto)
Flags: needinfo?(gijskruitbosch+bugs)
Flags: needinfo?(brennie)
See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1740301
Whiteboard: [stockwell disabled][comment 67][stockwell unknown] → [stockwell disabled][comment 67][stockwell needswork:owner]

(In reply to :Gijs (he/him) from comment #91)

Also, Mark, what's up with these errors, even on runs 9/10 of the test:

[task 2021-12-02T17:34:36.201Z] 17:34:36     INFO -  PID 1767 | console.error: "Could not load engine ddg@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: callAddonListeners :: line 1580\"  data: no]"
[task 2021-12-02T17:34:36.202Z] 17:34:36     INFO -  PID 1767 | console.error: "Could not load engine ebay@search.mozilla.org: [Exception... \"AddonManager is not initialized\"  nsresult: \"0xc1f30001 (NS_ERROR_NOT_INITIALIZED)\"  location: \"JS frame :: resource://gre/modules/AddonManager.jsm :: installBuiltinAddon :: line 2543\"  data: no]"
[task 2021-12-02T17:34:36.202Z] 17:34:36     INFO -  PID 1767 | console.warn: SearchService: "_init: abandoning init due to shutting down"

I guess we should make the test wait for startup to have finished before shutting down, to guarantee more reasonable behaviour?

This seems to be the case. If I'm reading the talos test correctly it essentially waits for sessionstore-state-finalized. As soon as that happens it does the logging and starts shutting down.

I did a quick profile on a local build, sessionstore-state-finalized happens after final-ui-startup, however it looks like it is right in the middle of the extension manager startup and just before the search service starts. That would explain the logging that is happening here.

This could be a clue for bug 1740301 since that could mean that an exists call is happening as shutdown is fired (I'll take this part there).

Flags: needinfo?(standard8)

(In reply to :Gijs (he/him) from comment #91)

So this is actually a startup issue, but it's not clear to me what causes it or how to investigate further. The fact that the crash dump is unreadable (I guess that's bug 1614931, Gabriele?) doesn't help.

Yes, that's the right bug. We might be able to address it soonish as @Gankra wanted to rewrite the macOS minidump writer in Rust and I'll be helping her along. With some luck we can get this fixed or at least surface an error that tells us why it's happening.

Flags: needinfo?(gsvelto)
Depends on: 1744794
Flags: needinfo?(brennie)

:afinder is working on enabling gecko profiling data submission in perfherder, but the profiling jobs are deactivated due to past intermittents. A recent try run didn't reveal any more intermittents, so we might want to enable those jobs before enabling data submission at all.

:aerickson, could we try resetting the windows10-64-ref-hw-2017-qr hardware to see if it fixes the uptick in failures?

If that doesn't work, then I'll request a backfill.

Flags: needinfo?(aerickson)

Redirecting to :mcornmesser

Flags: needinfo?(aerickson) → needinfo?(mcornmesser)

I have a request into to Bitbar to redeploy these laptops.

Flags: needinfo?(mcornmesser)

Reached out to Bitbar . Currently waiting on them to provide a time frame for redeployment.

The won't be able to do a redeploy until next week.

These laptops will be redeployed today.

Thanks :markco!

:mconley, do you think these failures are related to any of the patches to Talos that you've done in the last few weeks? They seem to only be occurring on mozilla-beta.

Flags: needinfo?(mconley)

No more failures after the 18th! :barret, do you think one of the patches you uplifted solved this issue?

Flags: needinfo?(mconley) → needinfo?(brennie)

It might be the patch from bug 1753957, but I'm not sure.

Flags: needinfo?(brennie)

There have been 53 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • macosx1015-64-shippable-qr
  • windows10-64-2004-shippable-qr
  • windows10-64-shippable-qr
Flags: needinfo?(gmierz2)

The backfills are all passing. Looking at the crash that I see (which is consistent in all failures):

[task 2022-08-24T11:43:15.998Z] 11:43:15     INFO -  Thread 0 MainThread
[task 2022-08-24T11:43:15.998Z] 11:43:15     INFO -   0  win32u.dll!NtUserMsgWaitForMultipleObjectsEx + 0x14
[task 2022-08-24T11:43:15.998Z] 11:43:15     INFO -       rax = 0x0000000000001486    rdx = 0x0000000000000000
[task 2022-08-24T11:43:15.998Z] 11:43:15     INFO -       rcx = 0x0000000000000000    rbx = 0x0000000000000000
[task 2022-08-24T11:43:15.999Z] 11:43:15     INFO -       rsi = 0x00000000ffffffff    rdi = 0x0000007dc2bfeaa0
[task 2022-08-24T11:43:15.999Z] 11:43:15     INFO -       rbp = 0x00007ffaf8b7a370    rsp = 0x0000007dc2bfea28
[task 2022-08-24T11:43:15.999Z] 11:43:15     INFO -        r8 = 0x000001c7acf00020     r9 = 0x000000007ffea000
[task 2022-08-24T11:43:15.999Z] 11:43:15     INFO -       r10 = 0x00000fff5b9a47a0    r11 = 0x0000000100000000
[task 2022-08-24T11:43:15.999Z] 11:43:15     INFO -       r12 = 0x00007ffaf8b91380    r13 = 0x00007ffaf8b7a370
[task 2022-08-24T11:43:16.000Z] 11:43:16     INFO -       r14 = 0x0000000000236cc9    r15 = 0x00007ffaf8b90ac0
[task 2022-08-24T11:43:16.000Z] 11:43:16     INFO -       rip = 0x00007ffaf875a104
[task 2022-08-24T11:43:16.000Z] 11:43:16     INFO -      Found by: given as instruction pointer in context
[task 2022-08-24T11:43:16.000Z] 11:43:16     INFO -   1  user32.dll!unsigned long RealMsgWaitForMultipleObjectsEx(unsigned long,void * const *,unsigned long,unsigned long,unsigned long) + 0x1d
[task 2022-08-24T11:43:16.000Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rbp = 0x00007ffaf8b7a370
[task 2022-08-24T11:43:16.001Z] 11:43:16     INFO -       rsp = 0x0000007dc2bfea30    r12 = 0x00007ffaf8b91380
[task 2022-08-24T11:43:16.001Z] 11:43:16     INFO -       r13 = 0x00007ffaf8b7a370    r14 = 0x0000000000236cc9
[task 2022-08-24T11:43:16.001Z] 11:43:16     INFO -       r15 = 0x00007ffaf8b90ac0    rip = 0x00007ffaf8b90b5e
[task 2022-08-24T11:43:16.001Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.001Z] 11:43:16     INFO -   2  xul.dll!mozilla::widget::WinUtils::WaitForMessage(unsigned long) [WinUtils.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 815 + 0x1c]
[task 2022-08-24T11:43:16.002Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rbp = 0x00007ffaf8b7a370
[task 2022-08-24T11:43:16.002Z] 11:43:16     INFO -       rsp = 0x0000007dc2bfea70    r12 = 0x00007ffaf8b91380
[task 2022-08-24T11:43:16.002Z] 11:43:16     INFO -       r13 = 0x00007ffaf8b7a370    r14 = 0x0000000000236cc9
[task 2022-08-24T11:43:16.002Z] 11:43:16     INFO -       r15 = 0x00007ffaf8b90ac0    rip = 0x00007ffac1678509
[task 2022-08-24T11:43:16.002Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.003Z] 11:43:16     INFO -   3  xul.dll!nsAppShell::ProcessNextNativeEvent(bool) [nsAppShell.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 772 + 0x9]
[task 2022-08-24T11:43:16.003Z] 11:43:16     INFO -       rbx = 0x000001c7ad141040    rsi = 0x0000007dc2bfecb0
[task 2022-08-24T11:43:16.004Z] 11:43:16     INFO -       rdi = 0x0000000000000000    rbp = 0x00007ffaf8b7a370
[task 2022-08-24T11:43:16.004Z] 11:43:16     INFO -       rsp = 0x0000007dc2bfeb40    r12 = 0x000001c7ad15b9f0
[task 2022-08-24T11:43:16.004Z] 11:43:16     INFO -       r13 = 0x0000007dc2bfecb0    r14 = 0x000000000017dd01
[task 2022-08-24T11:43:16.004Z] 11:43:16     INFO -       r15 = 0x0000000000000000    rip = 0x00007ffac2d20e9e
[task 2022-08-24T11:43:16.004Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.005Z] 11:43:16     INFO -   4  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 1121 + 0x2ab]
[task 2022-08-24T11:43:16.005Z] 11:43:16     INFO -       rbx = 0x00007ffac2bc7440    rsi = 0x00007ffad7c86ea0
[task 2022-08-24T11:43:16.005Z] 11:43:16     INFO -       rdi = 0x000001c7ad15b9f8    rbp = 0x0000000000000000
[task 2022-08-24T11:43:16.005Z] 11:43:16     INFO -       rsp = 0x0000007dc2bfeeb0    r12 = 0x0000007dc2bff070
[task 2022-08-24T11:43:16.005Z] 11:43:16     INFO -       r13 = 0x000001c7ad15b9f0    r14 = 0x000001c7ad15b480
[task 2022-08-24T11:43:16.006Z] 11:43:16     INFO -       r15 = 0x00007ffac2bb0801    rip = 0x00007ffac2bb10cc
[task 2022-08-24T11:43:16.006Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.006Z] 11:43:16     INFO -   5  xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [MessagePump.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 107 + 0x28]
[task 2022-08-24T11:43:16.006Z] 11:43:16     INFO -       rbx = 0x000001c7ad15b480    rsi = 0x000001c7ad112dc0
[task 2022-08-24T11:43:16.006Z] 11:43:16     INFO -       rdi = 0x000001c7ad1412e0    rbp = 0x0000000000000000
[task 2022-08-24T11:43:16.007Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff240    r12 = 0x0000007dc2bff900
[task 2022-08-24T11:43:16.007Z] 11:43:16     INFO -       r13 = 0x0000007dc2bff270    r14 = 0x000001c7ad112de0
[task 2022-08-24T11:43:16.007Z] 11:43:16     INFO -       r15 = 0x00007ffac2bb0800    rip = 0x00007ffac2ea59cd
[task 2022-08-24T11:43:16.007Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.007Z] 11:43:16     INFO -   6  xul.dll!MessageLoop::RunHandler() [message_loop.cc:d3dc65398cce28924be6381cef27f3751233e7a9 : 374 + 0x15]
[task 2022-08-24T11:43:16.008Z] 11:43:16     INFO -       rbx = 0x00000000ad15b901    rsi = 0x000001c7ad1412e0
[task 2022-08-24T11:43:16.008Z] 11:43:16     INFO -       rdi = 0x000001c7ad15b480    rbp = 0x0000007dc2bff300
[task 2022-08-24T11:43:16.008Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff2e0    r12 = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.008Z] 11:43:16     INFO -       r13 = 0x0000007dc2bffa69    r14 = 0x00007ffadcdbf778
[task 2022-08-24T11:43:16.008Z] 11:43:16     INFO -       r15 = 0x0000000080004005    rip = 0x00007ffac1d6e8ef
[task 2022-08-24T11:43:16.009Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.009Z] 11:43:16     INFO -   7  xul.dll!MessageLoop::Run() [message_loop.cc:d3dc65398cce28924be6381cef27f3751233e7a9 : 356 + 0x4]
[task 2022-08-24T11:43:16.009Z] 11:43:16     INFO -       rbx = 0x00000000ad15b901    rsi = 0x0000007dc2bff358
[task 2022-08-24T11:43:16.009Z] 11:43:16     INFO -       rdi = 0x000001c7ad15b480    rbp = 0x000001c7ad103430
[task 2022-08-24T11:43:16.009Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff330    r12 = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.010Z] 11:43:16     INFO -       r13 = 0x0000007dc2bffa69    r14 = 0x00007ffadcdbf778
[task 2022-08-24T11:43:16.010Z] 11:43:16     INFO -       r15 = 0x0000000080004005    rip = 0x00007ffac137394e
[task 2022-08-24T11:43:16.010Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.010Z] 11:43:16     INFO -   8  xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 150 + 0xc]
[task 2022-08-24T11:43:16.010Z] 11:43:16     INFO -       rbx = 0x00000000ad15b901    rsi = 0x000001c7ad15b9f0
[task 2022-08-24T11:43:16.011Z] 11:43:16     INFO -       rbp = 0x000001c7ad103430    rsp = 0x0000007dc2bff390
[task 2022-08-24T11:43:16.011Z] 11:43:16     INFO -       r12 = 0x0000007dc2bff970    r13 = 0x0000007dc2bffa69
[task 2022-08-24T11:43:16.011Z] 11:43:16     INFO -       r14 = 0x00007ffadcdbf778    r15 = 0x0000000080004005
[task 2022-08-24T11:43:16.012Z] 11:43:16     INFO -       rip = 0x00007ffac14e6918
[task 2022-08-24T11:43:16.012Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.012Z] 11:43:16     INFO -   9  xul.dll!nsAppShell::Run() [nsAppShell.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 614 + 0x7]
[task 2022-08-24T11:43:16.012Z] 11:43:16     INFO -       rbx = 0x00000000ad15b901    rsi = 0x000001c7ad15b9f0
[task 2022-08-24T11:43:16.013Z] 11:43:16     INFO -       rdi = 0x00007ffac215ec80    rbp = 0x000001c7ad103430
[task 2022-08-24T11:43:16.013Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff3d0    r12 = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.013Z] 11:43:16     INFO -       r13 = 0x0000007dc2bffa69    r14 = 0x00007ffadcdbf778
[task 2022-08-24T11:43:16.013Z] 11:43:16     INFO -       r15 = 0x0000000080004005    rip = 0x00007ffac14e5728
[task 2022-08-24T11:43:16.013Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.014Z] 11:43:16     INFO -  10  xul.dll!nsAppStartup::Run() [nsAppStartup.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 295 + 0x10]
[task 2022-08-24T11:43:16.014Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rsi = 0x000001c7b7b18190
[task 2022-08-24T11:43:16.014Z] 11:43:16     INFO -       rdi = 0x000000000000000e    rbp = 0x000001c7ad103430
[task 2022-08-24T11:43:16.014Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff550    r12 = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.014Z] 11:43:16     INFO -       r13 = 0x0000007dc2bffa69    r14 = 0x000001c7b7b05220
[task 2022-08-24T11:43:16.015Z] 11:43:16     INFO -       r15 = 0x0000000080004005    rip = 0x00007ffac266fa31
[task 2022-08-24T11:43:16.015Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.015Z] 11:43:16     INFO -  11  xul.dll!XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 5919 + 0xdb9]
[task 2022-08-24T11:43:16.015Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rsi = 0x0000007dc2bff758
[task 2022-08-24T11:43:16.015Z] 11:43:16     INFO -       rdi = 0x000000000000000e    rbp = 0x000001c7ad103430
[task 2022-08-24T11:43:16.016Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff5a0    r12 = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.016Z] 11:43:16     INFO -       r13 = 0x0000007dc2bffa69    r14 = 0x000001c7b7b05220
[task 2022-08-24T11:43:16.016Z] 11:43:16     INFO -       r15 = 0x0000000080004005    rip = 0x00007ffac26a6607
[task 2022-08-24T11:43:16.016Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.016Z] 11:43:16     INFO -  12  xul.dll!XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 5975 + 0xf]
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -       rbx = 0x000001c7ad10b3a0    rsi = 0x0000007dc2bff970
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -       rdi = 0x0000007dc2bff9b0    rbp = 0x0000000000000003
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -       rsp = 0x0000007dc2bff950    r12 = 0x0000000000000003
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -       r13 = 0x0000000000000003    r14 = 0x0000007dc2bffb70
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -       r15 = 0x000001c7ad10b0c0    rip = 0x00007ffac13525b7
[task 2022-08-24T11:43:16.017Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.018Z] 11:43:16     INFO -  13  firefox.exe!wmain(int, wchar_t**) [nsWindowsWMain.cpp:d3dc65398cce28924be6381cef27f3751233e7a9 : 126 + 0x533]
[task 2022-08-24T11:43:16.018Z] 11:43:16     INFO -       rbx = 0x00000000624d6b43    rsi = 0x000001c7ad10b3a0
[task 2022-08-24T11:43:16.018Z] 11:43:16     INFO -       rdi = 0x0000000000000070    rbp = 0x0000000000000070
[task 2022-08-24T11:43:16.018Z] 11:43:16     INFO -       rsp = 0x0000007dc2bffab0    r12 = 0x0000000000000003
[task 2022-08-24T11:43:16.019Z] 11:43:16     INFO -       r13 = 0x0000000000000003    r14 = 0x000001c7ace67430
[task 2022-08-24T11:43:16.019Z] 11:43:16     INFO -       r15 = 0x000001c7ad10b0c0    rip = 0x00007ff66249c062
[task 2022-08-24T11:43:16.019Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.020Z] 11:43:16     INFO -  14  firefox.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x21]
[task 2022-08-24T11:43:16.020Z] 11:43:16     INFO -       rbx = 0x00007ffaf83c07a8    rsi = 0x0000000000000000
[task 2022-08-24T11:43:16.020Z] 11:43:16     INFO -       rdi = 0x000001c7ace67430    rbp = 0x0000000000000000
[task 2022-08-24T11:43:16.020Z] 11:43:16     INFO -       rsp = 0x0000007dc2bffdf0    r12 = 0x0000000000000000
[task 2022-08-24T11:43:16.020Z] 11:43:16     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -       r15 = 0x0000000000000000    rip = 0x00007ff6624ab978
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -  15  kernel32.dll!BaseThreadInitThunk + 0x13
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rsi = 0x0000000000000000
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -       rdi = 0x0000000000000000    rbp = 0x0000000000000000
[task 2022-08-24T11:43:16.021Z] 11:43:16     INFO -       rsp = 0x0000007dc2bffe30    r12 = 0x0000000000000000
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -       r15 = 0x0000000000000000    rip = 0x00007ffaf99b7034
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -      Found by: call frame info
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -  16  ntdll.dll!RtlUserThreadStart + 0x20
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -       rbx = 0x0000000000000000    rbp = 0x0000000000000000
[task 2022-08-24T11:43:16.022Z] 11:43:16     INFO -       rsp = 0x0000007dc2bffe60    r12 = 0x0000000000000000
[task 2022-08-24T11:43:16.023Z] 11:43:16     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2022-08-24T11:43:16.023Z] 11:43:16     INFO -       r15 = 0x0000000000000000    rip = 0x00007ffafab22651
[task 2022-08-24T11:43:16.023Z] 11:43:16     INFO -      Found by: call frame info

Here's a link to this failing log: https://firefoxci.taskcluster-artifacts.net/VOpdMc_-R22zw0m7I61dKQ/0/public/logs/live_backing.log

I'm seeing the top frame crashing/hanging while waiting for a message in some code in Core :: Widget. :spohl, given that you're triage owner for that component do you think you could help with this failure, or would be able to direct me to someone else?

Flags: needinfo?(gmierz2)

See comment #148.

Flags: needinfo?(spohl.mozilla.bugs)

David, would you mind triaging this one? Thank you

Flags: needinfo?(spohl.mozilla.bugs) → needinfo?(davidp99)

That log was for this job. The range in comment 147 is a solid guess based on the change in frequency of crashes. Note: this changelist range is also behind the increase in mochitest failures in bug 1784591 -- but these runs seem to be failing much later and in random spots in the list of URLs to test.

Severity: S4 → S3
Flags: needinfo?(davidp99)
Priority: P5 → P3

Hi Mike! Can you maybe help with some suggestions on these failures ? Here is the most recent failure for Windows: https://treeherder.mozilla.org/logviewer?job_id=396016145&repo=autoland&lineNumber=992.

Flags: needinfo?(mconley)

Hi! Sorry for the delay. There appear to be to issues in the test run linked to in comment 19:

  1. Starting "resource monitoring" fails. That's using something called mozsystemmonitor, which I'm not familiar with. It seems to be failing to launch a separate process.
  2. The second is quite bizarre - the tabswitch Talos test uses a WebExtension with experimental capabilities to power the test. The test is failing because one of the scripts it loads in all content processes (tabswitch-content-process.js) is claiming that it cannot find the WebExtension policy for the extension is belongs to here: https://searchfox.org/mozilla-central/rev/028c68d5f32df54bca4cf96376f79e48dfafdf08/testing/talos/talos/tests/tabswitch/content/tabswitch-content-process.js#17-18

Which seems like a contradiction... the policy must exist because the WebExtension is running because the script that's hitting the error belongs to the WebExtension...

I'm going to redirect to mixedpuppy for a second here.. can you think of a reason why the policy might not be set despite a script from the extension running?

Flags: needinfo?(mconley) → needinfo?(mixedpuppy)
Assignee: gmierz2 → nobody
Status: ASSIGNED → NEW
Duplicate of this bug: 1789764
Flags: needinfo?(mixedpuppy)

Due to recent changes in how we will track bugs for crashes, the failure line here has changed to this None [unknown top frame] | , I'm going to update the bug summary here to reflect these changes and to avoid further duplicates for this bug.

Recent failure log:

[task 2023-07-19T18:04:27.315Z] 18:04:27     INFO -  PID 976 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-07-19T18:04:32.162Z] 18:04:32     INFO -  PID 976 | BROWSER FAILED TO GENERATE MOZAFTERPAINT IN 5 SECONDS
[task 2023-07-19T18:04:32.163Z] 18:04:32     INFO -  PID 976 | __startTimestamp5345.96__endTimestamp
[task 2023-07-19T18:04:57.018Z] 18:04:57     INFO -  PID 976 | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 324))
[task 2023-07-19T18:04:59.284Z] 18:04:59     INFO -  PID 976 | 1689789899283	addons.xpi	ERROR	System addon update list error Error: Failed downloading XML, status: 0, channelStatus: 2152398861, errorCode: 2, reason: error
[task 2023-07-19T18:05:10.173Z] 18:05:10     INFO -  Browser shutdown timed out after 20 seconds, killing process.
[task 2023-07-19T18:05:10.180Z] 18:05:10     INFO -  mozcrash Writing a dump to C:\Users\task_1689788063\AppData\Local\Temp\tmpxgx_tb1a\profile\minidumps\71445c84-1d7e-4b57-a925-e3731158c135.dmp for [1396]
[task 2023-07-19T18:05:10.378Z] 18:05:10     INFO -  mozcrash checking C:\Users\task_1689788063\AppData\Local\Temp\tmpxgx_tb1a\profile\minidumps for minidumps...
[task 2023-07-19T18:05:10.378Z] 18:05:10     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QsP8HuRdQM6Mu0n_PHUC7g/artifacts/public/build/target.crashreporter-symbols.zip
[task 2023-07-19T18:05:27.588Z] 18:05:27     INFO -  mozcrash Copy/paste: C:/Users/task_1689788063/fetches\minidump-stackwalk\minidump-stackwalk.exe --symbols-url=https://symbols.mozilla.org/ --cyborg=C:\Users\task_1689788063\AppData\Local\Temp\tmp55fj_qxr\71445c84-1d7e-4b57-a925-e3731158c135.trace C:\Users\task_1689788063\AppData\Local\Temp\tmpxgx_tb1a\profile\minidumps\71445c84-1d7e-4b57-a925-e3731158c135.dmp C:\Users\task_1689788063\AppData\Local\Temp\tmpb_f4740i
[task 2023-07-19T18:05:33.524Z] 18:05:33     INFO -  mozcrash Saved minidump as C:\Users\task_1689788063\build\blobber_upload_dir\71445c84-1d7e-4b57-a925-e3731158c135.dmp
[task 2023-07-19T18:05:33.528Z] 18:05:33     INFO -  PROCESS-CRASH | None [unknown top frame] | ts_paint_webext
[task 2023-07-19T18:05:33.528Z] 18:05:33     INFO -  Crash dump filename: C:\Users\task_1689788063\AppData\Local\Temp\tmpxgx_tb1a\profile\minidumps\71445c84-1d7e-4b57-a925-e3731158c135.dmp
[task 2023-07-19T18:05:33.528Z] 18:05:33     INFO -  Process type: unknown
[task 2023-07-19T18:05:33.528Z] 18:05:33     INFO -  Process pid: 1396
[task 2023-07-19T18:05:33.528Z] 18:05:33     INFO -  Operating system: Windows NT
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -                    10.0.17134
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -  CPU: amd64
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -       family 6 model 94 stepping 3
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -       8 CPUs
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -  No crash
[task 2023-07-19T18:05:33.529Z] 18:05:33     INFO -  Process uptime: 44 seconds
[task 2023-07-19T18:05:33.530Z] 18:05:33     INFO -  Thread 0 MainThread
[task 2023-07-19T18:05:33.530Z] 18:05:33     INFO -   0  win32u.dll!NtUserMsgWaitForMultipleObjectsEx + 0x14
[task 2023-07-19T18:05:33.530Z] 18:05:33     INFO -       rax = 0x0000000000001436    rdx = 0x0000000000000000
[task 2023-07-19T18:05:33.530Z] 18:05:33     INFO -       rcx = 0x0000000000000000    rbx = 0x0000000000000000
[task 2023-07-19T18:05:33.531Z] 18:05:33     INFO -       rsi = 0x00000000ffffffff    rdi = 0x00000000000a19c1
[task 2023-07-19T18:05:33.531Z] 18:05:33     INFO -       rbp = 0x0000000000000001    rsp = 0x00000013b31fdad8
[task 2023-07-19T18:05:33.531Z] 18:05:33     INFO -        r8 = 0x0000000000045000     r9 = 0x0000000000000020
[task 2023-07-19T18:05:33.531Z] 18:05:33     INFO -       r10 = 0x00000000ffffffdf    r11 = 0x000001db51b164e0
[task 2023-07-19T18:05:33.531Z] 18:05:33     INFO -       r12 = 0x00007ffd8e9c0200    r13 = 0x00007ffd8e9c0b40
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -       r14 = 0x00000013b31fdb50    r15 = 0x00007ffd8e9b84c0
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -       rip = 0x00007ffd8dae96e4
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -      Found by: given as instruction pointer in context
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -   1  user32.dll!unsigned long RealMsgWaitForMultipleObjectsEx(unsigned long,void * const *,unsigned long,unsigned long,unsigned long) + 0x1c
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rbp = 0x0000000000000001
[task 2023-07-19T18:05:33.532Z] 18:05:33     INFO -       rsp = 0x00000013b31fdae0    r12 = 0x00007ffd8e9c0200
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -       r13 = 0x00007ffd8e9c0b40    r14 = 0x00000013b31fdb50
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -       r15 = 0x00007ffd8e9b84c0    rip = 0x00007ffd8e9c029d
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -   2  xul.dll!mozilla::widget::WinUtils::WaitForMessage(unsigned long) [WinUtils.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 471 + 0x1c]
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rbp = 0x0000000000000001
[task 2023-07-19T18:05:33.533Z] 18:05:33     INFO -       rsp = 0x00000013b31fdb20    r12 = 0x00007ffd8e9c0200
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -       r13 = 0x00007ffd8e9c0b40    r14 = 0x00000013b31fdb50
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -       r15 = 0x00007ffd8e9b84c0    rip = 0x00007ffd5004bd88
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -   3  xul.dll!nsAppShell::ProcessNextNativeEvent(bool) [nsAppShell.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 661 + 0x9]
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -       rbx = 0x000000000000a701    rsi = 0x000001db51cfd580
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -       rdi = 0x0000000000000000    rbp = 0x0000000000000001
[task 2023-07-19T18:05:33.534Z] 18:05:33     INFO -       rsp = 0x00000013b31fdbf0    r12 = 0x000001db4424a5c0
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -       r13 = 0x0000000000000000    r14 = 0x00000013b31fdc40
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -       r15 = 0x00000013b31fdd70    rip = 0x00007ffd4fee1a5a
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -   4  xul.dll!nsBaseAppShell::DoProcessNextNativeEvent(bool) [nsBaseAppShell.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 131]
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -   5  xul.dll!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 267]
[task 2023-07-19T18:05:33.535Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -   6  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 1114 + 0x7f]
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -       rbx = 0x00007ffd6ee760e0    rsi = 0x000001db44261ac0
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -       rdi = 0x000001db51cfd588    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -       rsp = 0x00000013b31fdf70    r12 = 0x0000000000000000
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -       r13 = 0x00000000000a19c1    r14 = 0x000001db51cfd5e0
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -       r15 = 0x000001db44266301    rip = 0x00007ffd5175819f
[task 2023-07-19T18:05:33.536Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -   7  xul.dll!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 480]
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -   8  xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [MessagePump.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 107 + 0x34]
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rsi = 0x000001db4420ba80
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -       rdi = 0x000001db4424a190    rbp = 0x000001db51dea8b0
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -       rsp = 0x00000013b31fe450    r12 = 0x000001db51dea8f0
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -       r13 = 0x000001db44261ac0    r14 = 0x000001db5366dd00
[task 2023-07-19T18:05:33.537Z] 18:05:33     INFO -       r15 = 0x000001db51dea920    rip = 0x00007ffd51a9afd8
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -   9  xul.dll!MessageLoop::RunInternal() [message_loop.cc:898b3ffbdca34afc5fd0304f07f769e3d243265e : 370]
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -  10  xul.dll!MessageLoop::RunHandler() [message_loop.cc:898b3ffbdca34afc5fd0304f07f769e3d243265e : 363 + 0x15]
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rsi = 0x000001db4424a190
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -       rdi = 0x000001db44261ac0    rbp = 0x00000013b31fe6a0
[task 2023-07-19T18:05:33.538Z] 18:05:33     INFO -       rsp = 0x00000013b31fe680    r12 = 0x00000013b31feb48
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -       r13 = 0x00000013b31fe998    r14 = 0x00000013b31fe6f0
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -       r15 = 0x00007ffd89aba978    rip = 0x00007ffd50773f5f
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -  11  xul.dll!MessageLoop::Run() [message_loop.cc:898b3ffbdca34afc5fd0304f07f769e3d243265e : 345]
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -  12  xul.dll!nsBaseAppShell::Run() [nsBaseAppShell.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 148 + 0x3f]
[task 2023-07-19T18:05:33.539Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rsi = 0x000001db51cfd580
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -       rdi = 0x000001db44261ac0    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -       rsp = 0x00000013b31fe6d0    r12 = 0x00000013b31feb48
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -       r13 = 0x00000013b31fe998    r14 = 0x00000013b31fe6f0
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -       r15 = 0x00007ffd89aba978    rip = 0x00007ffd4fee1262
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -  13  xul.dll!nsAppShell::Run() [nsAppShell.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 520 + 0x7]
[task 2023-07-19T18:05:33.540Z] 18:05:33     INFO -       rbx = 0x000001db525d4080    rsi = 0x0000000000000000
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       rdi = 0x000001db51cfd580    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       rsp = 0x00000013b31fe740    r12 = 0x00000013b31feb48
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       r13 = 0x00000013b31fe998    r14 = 0x000001db51dbd9a0
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       r15 = 0x00007ffd89aba978    rip = 0x00007ffd4fee0d3a
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -  14  xul.dll!nsAppStartup::Run() [nsAppStartup.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 295 + 0xc]
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       rbx = 0x00000013b31fed00    rsi = 0x000001db51d29040
[task 2023-07-19T18:05:33.541Z] 18:05:33     INFO -       rdi = 0x000001db4420a330    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -       rsp = 0x00000013b31fe8c0    r12 = 0x00000013b31feb48
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -       r13 = 0x00000013b31fe998    r14 = 0x000001db51dbd9a0
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -       r15 = 0x000001db51d29040    rip = 0x00007ffd54b6d251
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -  15  xul.dll!XREMain::XRE_mainRun() [nsAppRunner.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 5661 + 0xf]
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -       rbx = 0x00000013b31fed00    rsi = 0x00000013b31feac4
[task 2023-07-19T18:05:33.542Z] 18:05:33     INFO -       rdi = 0x000001db4420a330    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       rsp = 0x00000013b31fe910    r12 = 0x00000013b31feb48
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       r13 = 0x00000013b31fe998    r14 = 0x000001db51dbd9a0
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       r15 = 0x000001db51d29040    rip = 0x00007ffd54be792f
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -  16  xul.dll!XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 5862 + 0x7]
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       rbx = 0x000001db442034f0    rsi = 0x00000013b31fed00
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       rdi = 0x000001db44211b30    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.543Z] 18:05:33     INFO -       rsp = 0x00000013b31fec30    r12 = 0x000001db4425e4c0
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -       r13 = 0x0000000000000004    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -       r15 = 0x000001db4425e4c0    rip = 0x00007ffd54be87cc
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -  17  xul.dll!XRE_main(int, char**, mozilla::BootstrapConfig const&) [nsAppRunner.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 5918 + 0x7]
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -       rbx = 0x000001db44204280    rsi = 0x00000013b31fed00
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -       rdi = 0x000001db43e6bae0    rbp = 0x0000000000000004
[task 2023-07-19T18:05:33.544Z] 18:05:33     INFO -       rsp = 0x00000013b31fece0    r12 = 0x000001db442044c0
[task 2023-07-19T18:05:33.545Z] 18:05:33     INFO -       r13 = 0x0000000000000004    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.545Z] 18:05:33     INFO -       r15 = 0x00007ff6fdf88241    rip = 0x00007ffd521681e5
[task 2023-07-19T18:05:33.545Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.545Z] 18:05:33     INFO -  18  firefox.exe!do_main(int, char**, char**) [nsBrowserApp.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 227]
[task 2023-07-19T18:05:33.545Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -  19  firefox.exe!NS_internal_main(int, char**, char**) [nsBrowserApp.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 445]
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -  20  firefox.exe!wmain(int, wchar_t**) [nsWindowsWMain.cpp:898b3ffbdca34afc5fd0304f07f769e3d243265e : 167 + 0x1a1]
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -       rbx = 0x000001db44204280    rsi = 0x000001db442044c0
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -       rdi = 0x000001db43e6bae0    rbp = 0x0000000000000004
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -       rsp = 0x00000013b31fedb0    r12 = 0x000001db442044c0
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -       r13 = 0x0000000000000004    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.546Z] 18:05:33     INFO -       r15 = 0x00007ff6fdf88241    rip = 0x00007ff6fdf4ee6f
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -  21  firefox.exe!invoke_main() [exe_common.inl : 90]
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -      Found by: inlining
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -  22  firefox.exe!__scrt_common_main_seh() [exe_common.inl : 288 + 0x21]
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -       rbx = 0x000001db43e67a20    rsi = 0x0000000000000000
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -       rdi = 0x000001db43e78c50    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -       rsp = 0x00000013b31ffa30    r12 = 0x0000000000000000
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.547Z] 18:05:33     INFO -       r15 = 0x0000000000000000    rip = 0x00007ff6fdf617b8
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -  23  kernel32.dll!BaseThreadInitThunk + 0x13
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rsi = 0x0000000000000000
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -       rdi = 0x0000000000000000    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -       rsp = 0x00000013b31ffa70    r12 = 0x0000000000000000
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -       r15 = 0x0000000000000000    rip = 0x00007ffd8f763034
[task 2023-07-19T18:05:33.548Z] 18:05:33     INFO -      Found by: call frame info
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -  24  ntdll.dll!RtlUserThreadStart + 0x20
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -       rbx = 0x0000000000000000    rbp = 0x0000000000000000
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -       rsp = 0x00000013b31ffaa0    r12 = 0x0000000000000000
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -       r13 = 0x0000000000000000    r14 = 0x0000000000000000
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -       r15 = 0x0000000000000000    rip = 0x00007ffd90d61461
[task 2023-07-19T18:05:33.550Z] 18:05:33     INFO -      Found by: call frame info
Summary: Intermittent <talos>| application crashed [unknown top frame] → Intermittent PROCESS-CRASH | None [unknown top frame] | <talos>
Duplicate of this bug: 1844224

both gtest and talos have this same bug and the top items on the stack look similar enough. I am going to mark this as a duplicate so we can track this specific failure in more detail.

Status: NEW → RESOLVED
Closed: 1 year ago
Duplicate of bug: 1839048
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: