Rust support is apparently broken

[dwlsalmeida]

Rust support is apparently broken, as per https://github.com/rust-lang/rust/pull/96238

It seems like the Rust compiler has stopped inserting the mcount instrumentation at all, which can be verified by something like:

rustc +nightly -Z instrument-mcount hello_world.rs nm hello_world | grep mcount

Where nothing will show up.

Maybe a warning should be added to the README.md file? I lost a couple hours thinking I failed to properly pass the -Z instrument-mcount flag to the Rust compiler.

[honggyukim]

Hi @dwlsalmeida, thanks for the report but it looks a duplicate issue with #1392.

Could you try again with the following workaround as mentioned at https://github.com/namhyung/uftrace/issues/1392#issuecomment-1047195716?

rustc +nightly -Zinstrument-mcount -C passes="ee-instrument post-inline-ee-instrument" hello_world.rs

[eddie9712]

Hi @honggyukim , I think the workaround #1392 still doesn't work with the newest Rust compiler (rustc 1.64.0-nightly (f2d93935f 2022-07-02)). I had tried this workaround and then I got the error: error: failed to run LLVM passes: unknown function pass 'post-inline-ee-instrument'. However, if I used the earlier Rust compiler (nightly-2021-12-02-x86_64-unknown-linux-gnu) this workaround could work normally. BTW, I saw the PR#96238 was working in progress so maybe we need to wait until this PR become available.

[honggyukim]

Thanks for your explanation. It seems there is definitely a problem adding mcount call in Rust compiler.

Sorry but it looks like beyond my knowledge for now as it's related Rust and LLVM compilers. I will investigate more when I have enough time for this.

As a workaround, I think you can still run uftrace for Rust program with full dynamic tracing. https://github.com/namhyung/uftrace/blob/master/doc/uftrace-record.md#full-dynamic-tracing

For example, if there is a program fib.rs as follows.

$ cat fib.rs
fn fibonacci(n: u32) -> u32 {
    match n {
        0 => 1,
        1 => 1,
        _ => fibonacci(n - 1) + fibonacci(n - 2),
    }
}

fn main() {
    fibonacci(5);
}

You can compile it even without -Z instrument-mcount option.

$ rustc -g fib.rs

If you run uftrace with the executable binary, uftrace complains that this binary doesn't have mcount.

$ uftrace fib
uftrace: /home/honggyu/work/uftrace/cmds/record.c:1660:check_binary
 ERROR: Can't find 'mcount' symbol in the 'fib'.
        It seems not to be compiled with -pg or -finstrument-functions flag.
        You can rebuild your program with it or use -P option for dynamic tracing.

But you can force adding mcount like hooks at the entry of each function with full dynamic tracing as follows.

$ uftrace -P. -a --no-libcall fib
# DURATION     TID     FUNCTION
            [ 52115] | main() {
            [ 52115] |   std::rt::lang_start(0x7ffce301b828, 0x100011c00, &main) {
            [ 52115] |     std::rt::lang_start_internal() {
   5.903 us [ 52115] |       std::sys::unix::stack_overflow::imp::make_handler();
   0.345 us [ 52115] |       __rdl_alloc();
   0.225 us [ 52115] |       std::ffi::c_str::CString::from_vec_unchecked();
   0.169 us [ 52115] |       __rdl_alloc();
            [ 52115] |       std::sys_common::thread_info::set() {
   1.047 us [ 52115] |         std::sys::unix::thread_local_dtor::register_dtor();
   1.428 us [ 52115] |       } /* std::sys_common::thread_info::set */
            [ 52115] |       std::rt::lang_start::_{{closure}}() {
            [ 52115] |         std::sys_common::backtrace::__rust_begin_short_backtrace(0x7ffce301b700) {
            [ 52115] |           core::ops::function::FnOnce::call_once(&fib::main, 1) {
            [ 52115] |             fib::main() {
            [ 52115] |               fib::fibonacci(0x557b303ffd7e) {
            [ 52115] |                 fib::fibonacci(0x557b303ffd4b) {
            [ 52115] |                   fib::fibonacci(0x557b303ffc94) {
            [ 52115] |                     fib::fibonacci(0x557b303ffc94) {
   0.132 us [ 52115] |                       fib::fibonacci(0x557b303ffc94) = 1;
   0.144 us [ 52115] |                       fib::fibonacci(0x557b303ffc94) = 1;
   1.281 us [ 52115] |                     } = 2; /* fib::fibonacci */
   0.126 us [ 52115] |                     fib::fibonacci(0x557b303ffc94) = 1;
   1.876 us [ 52115] |                   } = 3; /* fib::fibonacci */
            [ 52115] |                   fib::fibonacci(0x557b303ffc94) {
   0.117 us [ 52115] |                     fib::fibonacci(0x557b303ffcd3) = 1;
   0.119 us [ 52115] |                     fib::fibonacci(0x557b303ffcd3) = 1;
   0.732 us [ 52115] |                   } = 2; /* fib::fibonacci */
   2.975 us [ 52115] |                 } = 5; /* fib::fibonacci */
            [ 52115] |                 fib::fibonacci(0x557b303ffd4b) {
            [ 52115] |                   fib::fibonacci(0x557b303ffcd3) {
   0.120 us [ 52115] |                     fib::fibonacci(0x557b303ffc94) = 1;
   0.123 us [ 52115] |                     fib::fibonacci(0x557b303ffc94) = 1;
   0.703 us [ 52115] |                   } = 2; /* fib::fibonacci */
   0.115 us [ 52115] |                   fib::fibonacci(0x557b303ffcd3) = 1;
   1.213 us [ 52115] |                 } = 3; /* fib::fibonacci */
   4.728 us [ 52115] |               } = 8; /* fib::fibonacci */
   5.039 us [ 52115] |             } /* fib::main */
   5.493 us [ 52115] |           } /* core::ops::function::FnOnce::call_once */
   6.000 us [ 52115] |         } /* std::sys_common::backtrace::__rust_begin_short_backtrace */
            [ 52115] |         _<() as std..process..Termination>::report(0x7ffce301b700) {
            [ 52115] |           _<std..process..ExitCode as std..process..Termination>::report(ExitCode{...}) {
   0.226 us [ 52115] |             std::sys::unix::process::process_common::ExitCode::as_i32(&std::sys::unix::args::imp::ARGV_INIT_ARRAY) = 0;
   0.856 us [ 52115] |           } = 0; /* _<std..process..ExitCode as std..process..Termination>::report */
   1.536 us [ 52115] |         } = 0; /* _<() as std..process..Termination>::report */
   8.121 us [ 52115] |       } = 0; /* std::rt::lang_start::_{{closure}} */
            [ 52115] |       std::sync::once::Once::call_inner() {
   4.966 us [ 52115] |         std::sync::once::Once::call_once::_{{closure}}();
   0.202 us [ 52115] |         _<std..sync..once..WaiterQueue as core..ops..drop..Drop>::drop();
   6.318 us [ 52115] |       } /* std::sync::once::Once::call_inner */
 150.287 us [ 52115] |     } /* std::rt::lang_start_internal */
 288.616 us [ 52115] |   } = 0; /* std::rt::lang_start */
 289.809 us [ 52115] | } /* main */
            [ 52115] | std::sys_common::thread_info::THREAD_INFO::__getit::destroy() {
   0.230 us [ 52115] |   alloc::sync::Arc<T>::drop_slow();
   0.664 us [ 52115] | } /* std::sys_common::thread_info::THREAD_INFO::__getit::destroy */

[namhyung]

Rust seems to use a newer LLVM with parameterized syntax like in this commit. Please try below:

$ rustc +nightly -Z instrument-mcount -C passes='ee-instrument<post-inline>'  hello.rs

$ nm hello | grep mcount
                 U mcount@GLIBC_2.2.5

[eddie9712]

@namhyung thanks for your suggestion, it works for me.