Impossible call stack

[last vortex]

I have a fairly simple test here, which seems to output an impossible call stack when profiled with perf:

use std::collections::HashMap;

#[inline(never)]
#[no_mangle]
fn merge(lhs: &mut HashMap<i32, f32>, rhs: &HashMap<i32, f32>) {
    for (k, v) in rhs {
        lhs.insert(*k, *v);
    }
}

#[no_mangle]
#[inline(never)]
fn merge_all(inputs: Vec<(HashMap<i32, f32>, HashMap<i32, f32>)>) {
    for (mut lhs, rhs) in inputs {
        merge(&mut lhs, &rhs);
        std::mem::forget(core::hint::black_box((lhs, rhs)));
    }
}

pub fn main() {
    for _ in 0..1000 {
        let mut a = HashMap::<i32, f32>::default();

        for key in 0..100 {
            a.insert(key, key as f32);
        }

        let mut b = HashMap::default();
        b.insert(-1, -1.0);

        let inputs = std::iter::from_fn(|| Some((a.clone(), b.clone())))
            .take(1000)
            .collect::<Vec<_>>();

        merge_all(inputs);
    }
}

[continuing in thread...]

Profile:

[profile.release]
debug = "full"
split-debuginfo = "off"

Build steps:

$ RUSTFLAGS="-C force-frame-pointers=yes" cargo +nightly -Z build-std build --release
$ sudo perf record --call-graph dwarf,16384 -F 20000 -k mono -- target/release/test-stacks
$ sudo perf report -g --percent-limit 0

An impossible stack:

    -   77.59%     0.00%  test-stacks  libc.so.6             [.] __libc_start_main@@GLIBC_2.34
         __libc_start_main@@GLIBC_2.34
         __libc_start_call_main
         main
         std::rt::lang_start_internal
         std::panic::catch_unwind (inlined)
         std::panicking::try (inlined)
         std::panicking::try::do_call (inlined)
       - std::rt::lang_start_internal::_$u7b$$u7b$closure$u7d$$u7d$::h645042a4ac672685 (inlined)
          - 77.58% std::panic::catch_unwind (inlined)
               std::panicking::try (inlined)
               std::panicking::try::do_call (inlined)
               core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once (inlined)
               _ZN3std2rt10lang_start28_$u7b$$u7b$closure$u7d$$u7d$17h290fa3747e989f63E.llvm.2712499214609531460
               std::sys::backtrace::__rust_begin_short_backtrace
               core::ops::function::FnOnce::call_once (inlined)
             - test_stacks::main
                + 73.73% core::iter::traits::iterator::Iterator::collect (inlined)
                + 2.26% hashbrown::map::HashMap<K,V,S,A>::insert
merge_all -->   - 1.04% merge_all
                   + 0.23% <alloc::vec::into_iter::IntoIter<T,A> as core::iter::traits::iterator::Iterator>::next (inlined)
                     0.12% core::hint::black_box (inlined)
                   - 0.11% merge
insert... ---->       - std::collections::hash::map::HashMap<K,V,S>::insert (inlined)
                         + 0.04% hashbrown::map::HashMap<K,V,S,A>::insert
merge_all? how? -->      - 0.02% merge_all
                            - <alloc::vec::into_iter::IntoIter<T,A> as core::iter::traits::iterator::Iterator>::next (inlined)
                              core::ptr::non_null::NonNull<T>::read (inlined)
                              core::ptr::read (inlined)

How could merge_all be called inside HashMap::insert?

[old badge]

stack trace collection and labeling from executing machine code is not an exact science

there are also other factors, like that functions which are nominally different but compile to identical code may be combined and thus be given the same name, but in this case it looks like the stack the profiler collected is wrong somehow

[last vortex]

Would this be a bug in perf? The DWARF info rustc generates? Or maybe something else..?

[old badge]

or not a bug per se but it might be using some kind of approximate algorithm.
I don't personally know the technical details, I just know that wrongly-labeled stacks are to be expected sometomes.