-O2: WARN: cannot open record data: /tmp/uftrace-live-7dmS9x: No data available

[vt-alt]

While testing separate-dwarf feature I noticed that uftrace sometimes not able to trace binaries compiled with -O2 without any explanation. (I found minimal example that does not trace even with -O0):

$ cat a.c
#include <unistd.h>
int main(int argc, char **argv)
{
        _exit(0);
}
$ gcc -O2 -g a.c -o a
$ uftrace -P. ./a
WARN: cannot open record data: /tmp/uftrace-live-dzzwyD: No data available

But aren't there is at least a main call? strace -k show there is _exit and main in backtrace:

strace -k ./a
...
exit_group(0)                           = ?
+++ exited with 0 +++
 > /lib64/libc.so.6(_exit+0x15) [0xd6575]
 > /home/vt/src/uftrace/a(main+0xc) [0x105c]
 > /lib64/libc.so.6(__libc_start_call_main+0x7b) [0x27c8b]
 > /lib64/libc.so.6(__libc_start_main@@GLIBC_2.34+0x84) [0x27d44]
 > /home/vt/src/uftrace/a(_start+0x20) [0x1080]

Also, gdb is able to stop at main so the symbols is there:

$ gdb -q ./a
Reading symbols from ./a...
(gdb) b main
Breakpoint 1 at 0x1050: file a.c, line 3.
(gdb) r
Starting program: /home/vt/src/uftrace/a
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
=> 0x555555555050 <main>:       push   %rax

Breakpoint 1, main (argc=1, argv=0x7fffffffd9a8) at a.c:3
3       {
(gdb) quit

While this simple case is not useful in itself (except as an example) I fear it would miss some calls for a normal tracing, because -O2 compilation is very common.

[namhyung]

I don't think it's related to -O2, does it work with -O0? Basically uftrace records the trace when it returns (due to time filter). But _exit() never returns. Anyway, I guess calling _exit() directly is rare..

[vt-alt]

Yes my example is just minified but maybe I minified it too much. I found it first with rpm --querytags:

$ uftrace -P. rpm --querytags
...
WARN: cannot open record data: /tmp/uftrace-live-LsgHZR: No data available

Also with this example code:

$ cat a.c
void foo(int a) { }
int main(int argc, char **argv)
{
        foo(1);
        return 0;
}
$ gcc -O1 -g -o a a.c
$ uftrace -P. ./a
# DURATION     TID     FUNCTION
   0.282 us [3595069] | main();
$ gcc -O2 -g -o a a.c
$ uftrace -P. ./a
WARN: cannot open record data: /tmp/uftrace-live-KKs2Bq: No data available

Yes foo is optimized out for -O2 (and gdb does not break there) but main is still there (gdb breaks there).

[namhyung]

Can you share the disassembly of the main function with -O2? I'm curious if it has ret instruction at the end.

[vt-alt]

Of course. For the above source (for-O1 and -O2):

$ gcc -O1 -g a.c -o a
$ uftrace -P. ./a
# DURATION     TID     FUNCTION
   0.266 us [3788811] | main();
$ gdb -batch -ex 'disassemble main' ./a
Dump of assembler code for function main:
   0x000000000000112a <+0>:     mov    $0x0,%eax
   0x000000000000112f <+5>:     ret
End of assembler dump.

$ gcc -O2 -g a.c -o a
$ uftrace -P. ./a
WARN: cannot open record data: /tmp/uftrace-live-Zinsjj: No data available

$ gdb -batch -ex 'disassemble main' ./a
Dump of assembler code for function main:
   0x0000000000001040 <+0>:     xor    %eax,%eax
   0x0000000000001042 <+2>:     ret
End of assembler dump.

(Function is too short to instrument?)

[namhyung]

Thanks for sharing this. You're right, it's too short. The dynamic tracing (on x86) requires functions at least 5 byte long (that's the size of call instruction).

[vt-alt]

Thanks for clarification!