Tracing Rust application built for armv7-unknown-linux-gnueabihf doesn't record end of function calls #1996
Description
We're trying to trace a Rust application on a target with the armv7-unknown-linux-gnueabihf target triple. It seems like uftrace is unable to detect when a Rust function call ends, calls to libc seem to work fine. We reproduced this with a minimal example:
pub fn g() {
println!("Hello world from g!");
}
pub fn f() {
println!("Hello world from the beginning of f!");
g();
println!("Hello world from the end of f!");
}
pub fn main() {
f();
}
Then the output of
> uftrace record ./dummy
> uftrace replay
shows the called functions, but the "scopes" never close. Also a list of remaining functions is given at the end. The functions from the example program can be found in the output. Full log.
Details
Target platform: Raspberry Pi 3 Model B Rev 1.2
Target OS: Raspbian GNU/Linux 12 (bookworm); 32 bit
uftrace Version: uftrace v0.17-10-ge726 ( arm dwarf python3 luajit tui perf sched dynamic kernel ); manually compiled
Cross compiling from x86_64 for armv7-unknown-linux-gnueabihf
See here.
Comparison to x86_64
uftrace works perfectly fine for the same Rust code on Ubuntu 22.04 on an x86_64 machine:
> RUSTFLAGS="-Z instrument-mcount -C passes=ee-instrument<post-inline>" cargo +nightly build
...
Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.10s
> uftrace target/debug/dummy
Hello world from the beginning of f!
Hello world from g!
Hello world from the end of f!
# DURATION TID FUNCTION
[ 82556] | std::rt::lang_start() {
[ 82556] | std::rt::lang_start::_{{closure}}() {
[ 82556] | std::sys::backtrace::__rust_begin_short_backtrace() {
[ 82556] | core::ops::function::FnOnce::call_once() {
[ 82556] | dummy::main() {
[ 82556] | dummy::f() {
0.147 us [ 82556] | core::fmt::Arguments::new_const();
[ 82556] | dummy::g() {
0.096 us [ 82556] | core::fmt::Arguments::new_const();
1.757 us [ 82556] | } /* dummy::g */
0.090 us [ 82556] | core::fmt::Arguments::new_const();
12.833 us [ 82556] | } /* dummy::f */
13.038 us [ 82556] | } /* dummy::main */
13.283 us [ 82556] | } /* core::ops::function::FnOnce::call_once */
13.510 us [ 82556] | } /* std::sys::backtrace::__rust_begin_short_backtrace */
0.071 us [ 82556] | _<() as std..process..Termination>::report();
14.044 us [ 82556] | } /* std::rt::lang_start::_{{closure}} */
294.500 us [ 82556] | } /* std::rt::lang_start */
Comparison to a simple C program
uftrace also works fine for a simple C program compiled on the target:
dummy.c
#include <stdio.h>
#include <unistd.h>
void g() {
printf("Hello world from g!\n");
}
void f() {
printf("Hello world from the beginning of f!\n");
g();
printf("Hello world from the end of f!\n");
}
int main() {
f();
}
compiled with
gcc -pg dummy.c
provides
> uftrace ./a.out
Hello world from the beginning of f!
Hello world from g!
Hello world from the end of f!
# DURATION TID FUNCTION
5.573 us [ 4457] | __monstartup();
4.532 us [ 4457] | __cxa_atexit();
[ 4457] | main() {
[ 4457] | f() {
[ 4457] | puts() {
66.666 us [ 4457] | /* linux:schedule (pre-empted) */
23.542 us [ 4457] | /* linux:schedule (pre-empted) */
205.364 us [ 4457] | } /* puts */
[ 4457] | g() {
[ 4457] | puts() {
26.823 us [ 4457] | /* linux:schedule (pre-empted) */
22.135 us [ 4457] | /* linux:schedule (pre-empted) */
99.740 us [ 4457] | } /* puts */
103.958 us [ 4457] | } /* g */
[ 4457] | puts() {
23.177 us [ 4457] | /* linux:schedule (pre-empted) */
26.615 us [ 4457] | /* linux:schedule (pre-empted) */
102.343 us [ 4457] | } /* puts */
423.696 us [ 4457] | } /* f */
427.342 us [ 4457] | } /* main */