1699684 - Telemetry stack walker doesn't completely unwind stack

Status: REOPENED

(Toolkit :: Crash Reporting, defect)

Description

[Jeff Muizelaar [:jrmuizel]]

Attachment: stack from telemetry

The Socorro version of the same crash on the same build unwinds properly:
https://crash-stats.mozilla.org/report/index/6d7e520a-dadb-4429-bda4-27e0b0210309

The telemetry version does not have a stack beyond webrender::scene_building::SceneBuilder::build_item

Comment 2

[Gabriele Svelto [:gsvelto]]

There is something extremely odd about this crash which might be a more general problem with the stackwalker. If you look at the JSON output in crash stats it is truncated and similar to the telemetry one. If on the other hand you disregard the crashing thread entry and go look for the stack trace in the list of threads then you find the larger trace as shown on the crash' "Details" tab.

Comment 3

[Aria Beingessner [:Gankra]]

Huh, weirdly the telemetry truncates to 11 frames, but the json is truncated to 10 frames. I'll need to apply for protected access to inspect the raw minidumps to see if they're corrupted or something.

Comment 4

[Gabriele Svelto [:gsvelto]]

Some discrepancies between the telemetry and Socorro are expected because for telemetry we use a different stack walker which reads the native unwinding tables instead of relying on .sym files. However if you look at the crash in comment 0 you'll notice that the trace of the crashed thread is different if you look it up in the threads list (see on the Raw Data and Minidumps tab). The stack trace in the threads entry looks like this:

  1. mozalloc_abort(char const* const)
  2. mozalloc_handle_oom(unsigned long long)
  3. gkrust_shared::oom_hook::hook(core::alloc::layout::Layout)
  4. std::alloc::rust_oom()
  5. alloc::alloc::__alloc_error_handler::__rg_oom()
  6. _rust_alloc_error_handler
  7. alloc::alloc::handle_alloc_error()
  8. hashbrown::raw::Fallibility::alloc_err()
  9. hashbrown::raw::RawTable<tuple<webrender_api::display_item::ClipId, webrender::clip::ClipTemplate>>::reserve_rehash<tuple<webrender_api::display_item::ClipId, webrender::clip::ClipTemplate>,closure-1>(unsigned long long, hashbrown::map::{{impl}}::insert::closure-1, hashbrown::raw::Fallibility)
 10. webrender::clip::ClipStore::register_clip_template(webrender_api::display_item::ClipId, webrender_api::display_item::ClipId, slice<webrender::clip::SceneClipInstance>*)
 11. webrender::scene_building::SceneBuilder::build_item(webrender_api::display_list::DisplayItemRef, webrender_api::PipelineId)
 12. webrender::scene_building::SceneBuilder::build_all(webrender::scene::ScenePipeline*)
 13. webrender::scene_builder_thread::SceneBuilderThread::process_transaction(webrender::render_api::TransactionMsg*)
 14. webrender::scene_builder_thread::SceneBuilderThread::run()
 15. std::sys_common::backtrace::__rust_begin_short_backtrace<closure-2,tuple<>>(webrender::renderer::{{impl}}::new::closure-2)
 16. core::ops::function::FnOnce::call_once<closure-0,tuple<>>(std::thread::{{impl}}::spawn_unchecked::closure-0*)
 17. std::sys::windows::thread::{{impl}}::new::thread_start()
 18. BaseThreadInitThunk
 19. RtlUserThreadStart
 20. BasepReportFault
 21. BasepReportFault

I suspect the same might be happening on telemetry given the output is generated using the same sources. That is the stack trace of the crashing thread is shorter compared to what shows up under the threads list.

Comment 5

[Aria Beingessner [:Gankra]]

We've learned that truncating the stack of the crashing_thread to 10 frames is actually intentional/designed in minidump-stackwalk, as it's just a "preview" "for ease of searching" but no one is around who remembers what the design intent was. Discussing what to do now.

Comment 6

[Aria Beingessner [:Gankra]]

Do I need to do anything to get these changes up into soccorro/telemetry, or is that automatic?

Comment 7

[Will Kahn-Greene [:willkg] ET needinfo? me]

It's not automatic. I need to do a minidump-stackwalk release (https://github.com/mozilla-services/minidump-stackwalk/issues/19) and then pull in the new version in socorro (bug tbd).

That won't fix the issues with data in telemetry.crash from the description.

Comment 8

[Aria Beingessner [:Gankra]]

Hmm right I was hoping I'd find a shared root cause but this seems pretty specific to the minidump-stackwalk impl. Where is the code that generates the telemetry json? I don't obviously see it in-tree (e.g. the string has_crash_environment doesn't show up in searchfox).

Comment 9

[Will Kahn-Greene [:willkg] ET needinfo? me]

The crash ping data comes from minidump-analyzer:

https://searchfox.org/mozilla-central/source/toolkit/crashreporter/minidump-analyzer

and CrashManager.jsm:

https://searchfox.org/mozilla-central/source/toolkit/components/crashes/CrashManager.jsm#708

When the crash ping data gets ingested by Telemetry, it normalizes the keys, so hasCrashEnvironment becomes has_crash_environment.

Comment 10

[Gabriele Svelto [:gsvelto]]

minidump-analyzer takes Breakpad "requesting thread" (that is the thread that requested the minidump, for crashes that's the thread the crash occurred on) and serializes that into JSON: https://searchfox.org/mozilla-central/rev/368607c4cd5be547021945e4ae60e8eb4365b3c4/toolkit/crashreporter/minidump-analyzer/minidump-analyzer.cpp#285-296

So whatever Breakpad gives us ends up there.

Comment 11

[Aria Beingessner [:Gankra]]

Oh I wonder if this is a result of Bug 1372830...

Comment 12

[Gabriele Svelto [:gsvelto]]

Yes, it could be.

Comment 13

[Aria Beingessner [:Gankra]]

I was going to say it's impossible for me to debug that from the minidump (since minidump-analyzer CFI handling is using native driver info), but this is dying in the middle of XUL, and the crash ping says it has xul.pdb loaded? Do we ship some debuginfo in our windows releases? Maybe I can download that version of firefox and boot up its minidump-analyzer...

(That said the stackwalk dies suspiciously close to a native symbol)

Comment 14

[Gabriele Svelto [:gsvelto]]

64-bit builds should have unwind tables baked into the PE. The PDB should only contain the rest of the debug information.

Comment 15

[Aria Beingessner [:Gankra]]

Huh strange, the nightlies for 2021-02-22 are 20210222214056 and 20210222084406 but this crash is 20210222142601 (21:40:56/08:44:06 vs 14:26:01). Could this be someone's local build?

(Gonna test with the evening nightly all the same, but, doubtful the CFI entries will line up)

Comment 16

[Aria Beingessner [:Gankra]]

Mm yeah, it just immediately falls back to scanning all the frames. I think I'm forced to assume that this issue is Bug 1372830, which should be fixed in its own right, either directly or with our future work rewriting our tooling in Rust.

Comment 17

[BugBot [:suhaib / :marco]]

Closing because no crashes reported for 12 weeks.

Comment 18

[Jeff Muizelaar [:jrmuizel]]

Removing the crash signature from the bug so this doesn't get autoclosed.

Comment 19

[Gabriele Svelto [:gsvelto]]

Jeff, the original crash in comment 0 is already lost in the sands of time, do you have another example of this behavior?

Comment 20

[Jeff Muizelaar [:jrmuizel]]

I wasn't able to find another example.

Comment 21

[Jeff Muizelaar [:jrmuizel]]

On beta our RustMozCrash crashes are failing to unwind through the Rust standard library:
https://mathies.com/mozilla/crashes/gpubeta.html

There are lots of crash reports that successfully do unwind:
https://crash-stats.mozilla.org/report/index/cab8a80c-22fa-4298-b44d-226530211014

Comment 22

[Gabriele Svelto [:gsvelto]]

Thanks!