search

namhyung / uftrace

Function graph tracer for C/C++/Rust/Python
https://uftrace.github.io/slide/
GNU General Public License v2.0
3.06k stars 474 forks source link

Segfault when tracing prebuilt firefox in strdup #744

Open honggyukim opened 5 years ago

honggyukim commented 5 years ago

Here is the log.

$ uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org
child terminated by signal: 11: Segmentation fault

With gdb

$ cgdb -q --args uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org

(gdb) r
Starting program: /home/honggyu/work/uftrace/uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
process 192059 is executing new program: /usr/lib/firefox/firefox
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Thread 2.1 "firefox" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff7fc4800 (LWP 192059)]
0x0000000000000000 in ?? ()
(gdb)

The backtrace is as follows:

(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x00007ffff571e080 in ?? ()
#2  0x0000000000000011 in ?? ()
#3  0x00005555555637a9 in strdup ()
#4  0x00007ffff7bc2170 in mcount_arch_hook_no_plt (elf=0x7fffffffdf20, modname=0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox", offset=93824992231424) at
/home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c:123
#5  0x00007ffff7ba4384 in find_got (elf=0x7fffffffdf20, iter=0x7fffffffdea0, modname=0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox", offset=9382499223142
4) at /home/honggyu/work/uftrace/libmcount/plthook.c:196
#6  0x00007ffff7ba49c9 in hook_pltgot (modname=0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox", offset=93824992231424) at /home/honggyu/work/uftrace/libmcount/plthook.c:306
#7  0x00007ffff7ba4f5f in setup_exe_plthook_data (info=0x7fffffffdff0, sz=64, arg=0x7ffff7dd4f40 <exename>) at /home/honggyu/work/uftrace/git/uftrace/new/dyna
mic/libmcount/plthook.c:506
#8  0x00007ffff6c410e4 in __GI___dl_iterate_phdr (callback=0x7ffff7ba4efa <setup_exe_plthook_data>, data=0x7ffff7dd4f40 <exename>) at dl-iteratephdr.c:76
#9  0x00007ffff7ba4fd1 in mcount_setup_plthook (exename=0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox", nest_libcall=false) at /home/honggyu/work/uftrace
/libmcount/plthook.c:518
#10 0x00007ffff7b9e8f5 in mcount_startup () at /home/honggyu/work/uftrace/libmcount/mcount.c:1742
#11 0x00007ffff7b9ead8 in mcount_init () at /home/honggyu/work/uftrace/libmcount/mcount.c:1842
#12 0x00007ffff7de76ca in call_init (l=<optimized out>, argc=argc@entry=3, argv=argv@entry=0x7fffffffe268, env=env@entry=0x7fffffffe288) at dl-init.c:72
#13 0x00007ffff7de77db in call_init (env=0x7fffffffe288, argv=0x7fffffffe268, argc=3, l=<optimized out>) at dl-init.c:30
#14 _dl_init (main_map=0x7ffff7ffe168, argc=3, argv=0x7fffffffe268, env=0x7fffffffe288) at dl-init.c:120
#15 0x00007ffff7dd7c6a in _dl_start_user () from /lib64/ld-linux-x86-64.so.2
#16 0x0000000000000003 in ?? ()
#17 0x00007fffffffe54d in ?? ()
#18 0x00007fffffffe566 in ?? ()
#19 0x00007fffffffe571 in ?? ()
#20 0x0000000000000000 in ?? ()
(gdb) up
#1  0x00007ffff571e080 in ?? ()

(gdb) up
#2  0x0000000000000011 in ?? ()
Warning: dissasemble address 0x11 failed.

(gdb) up
#3  0x00005555555637a9 in strdup ()

(gdb) up
#4  0x00007ffff7bc2170 in mcount_arch_hook_no_plt (elf=0x7fffffffdf20, modname=0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox", offset=93824992231424) at
/home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c:123
 22│ extern void __weak plt_hooker(void);
 23│ struct plthook_data * mcount_arch_hook_no_plt(struct uftrace_elf_data *elf,
 24│                                               const char *modname,
 25│                                               unsigned long offset)
 26│ {
 27│         struct plthook_data *pd;
 28│         void *trampoline;
 29│         size_t tramp_len;
 30│         uint32_t i;
 31│         const uint8_t tramp_plt0[] = {  /* followed by module_id + plthook_addr */
 32│                 /* PUSH module_id */
 33│                 0xff, 0x35, 0xa, 0, 0, 0,
 34│                 /* JMP plthook_addr */
 35│                 0xff, 0x25, 0xc, 0, 0, 0,
 36│                 0xcc, 0xcc, 0xcc, 0xcc,
 37│         };
 38│         const uint8_t tramp_insns[] = {  /* make stack what plt_hooker expect */
 39│                 /* PUSH child_idx */
 40│                 0x68, 0, 0, 0, 0,
 41│                 /* JMP plt0 */
 42│                 0xe9, 0, 0, 0, 0,
 43│                 /* should never reach here */
 44│                 0xcc, 0xcc, 0xcc, 0xcc, 0xcc, 0xcc,
 45│         };
 46│         void *plthook_addr = plt_hooker;
 47│         void *tramp;
...
121│         mprotect(trampoline, tramp_len, PROT_READ|PROT_EXEC);
122│
123├───────> pd->mod_name = xstrdup(modname);
124│
125│         return pd;
126│ }
/home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c
(gdb) p modname
$1 = 0x7ffff7dd4f40 <exename> "/usr/lib/firefox/firefox"

(gdb) p *pd
$2 = {
  list = {
    prev = 0x0,
    next = 0x0
  },
  mod_name = 0x0,
  module_id = 140737311268992,
  base_addr = 93824992231424,
  plt_addr = 0,
  dsymtab = {
    sym = 0x7ffff5723000,
    sym_names = 0x7ffff5747800,
    nr_sym = 104,
    nr_alloc = 104,
    name_sorted = false
  },
  pltgot_ptr = 0x7ffff7ff5000,
  resolved_addr = 0x7ffff5747c00,
  special_funcs = 0x0,
  nr_special = 0
}
(gdb) down
#3  0x00005555555637a9 in strdup ()
1│ Dump of assembler code for function strdup:
2│    0x00005555555637a0 <+0>:     push   rbx
3│    0x00005555555637a1 <+1>:     mov    rbx,rdi
4│    0x00005555555637a4 <+4>:     call   0x555555559ff8
5├──> 0x00005555555637a9 <+9>:     mov    rdi,rbx
6│    0x00005555555637ac <+12>:    mov    rsi,rax
7│    0x00005555555637af <+15>:    pop    rbx
8│    0x00005555555637b0 <+16>:    jmp    0x555555563760 <strndup>
9│ End of assembler dump.
(gdb) p/x $rdi
$4 = 0x7ffff7dd4f40

(gdb) p/x $rbx
$5 = 0x7ffff7dd4f40
honggyukim commented 5 years ago

Normal execution looks different as well even with --no-libcall.

$ uftrace record --force --no-libcall /usr/lib/firefox/firefox --headless https://www.mozilla.org
*** You are running in headless mode.
ExceptionHandler::GenerateDump cloned child 192459
ExceptionHandler::SendContinueSignalToChild sent continue signal to child
ExceptionHandler::WaitForContinueSignal waiting for continue signal...
Failed to connect to Mir: Failed to connect to server socket: No such file or directory
Unable to init server: Could not connect: Connection refused
*** You are running in headless mode.
ExceptionHandler::GenerateDump cloned child 192489
ExceptionHandler::SendContinueSignalToChild sent continue signal to child
ExceptionHandler::WaitForContinueSignal waiting for continue signal...
Failed to connect to Mir: Failed to connect to server socket: No such file or directory
Unable to init server: Could not connect: Connection refused

The original execution log is as follows:

$ /usr/lib/firefox/firefox --headless https://www.mozilla.org
*** You are running in headless mode.
*** You are running in headless mode.

However, it works same with -P dynamic tracing option.

$ uftrace record -P. --force --no-libcall /usr/lib/firefox/firefox --headless https://www.mozilla.org
*** You are running in headless mode.
*** You are running in headless mode.
$ uftrace graph
 Function Call Graph for 'python3.5' (session: 207157de4b92870c)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME   FUNCTION
  673.304 ms : (1) python3.5
  673.304 ms : (1) main
  673.131 ms : (1) Py_Main
  384.276 ms :  +-(1) Py_Initialize
    4.729 ms :  |  +-(4) PyType_Ready
             :  |  |
    1.488 ms :  |  +-(1) _PyBuiltin_Init
             :  |  |
    4.698 ms :  |  +-(1) _PyExc_Init
             :  |  |
    8.256 ms :  |  +-(1) PyImport_ImportFrozenModule
    8.248 ms :  |  | (1) PyImport_ImportFrozenModuleObject
    3.497 ms :  |  |  +-(1) PyMarshal_ReadObjectFromString
...

# Function Call Graph for 'firefox' (session: 5454c01a8b240c84)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME   FUNCTION
    7.029  m : (1) firefox
    5.058  m :  +-(442) mozilla::detail::ConditionVariableImpl::wait_for
    4.050  m :  |  +-(113) mozilla::detail::ConditionVariableImpl::wait
    4.050  m :  |  | (113) linux:schedule
             :  |  |
    1.007  m :  |  +-(328) linux:schedule
             :  |
    1.030  m :  +-(204) mozilla::detail::ConditionVariableImpl::wait
    1.030  m :  | (204) linux:schedule
             :  |
    1.650 ms :  +-(1) moz_xmalloc
    1.642 ms :  | (1) malloc
    1.606 ms :  | (1) linux:schedule
             :  |
    1.546 ms :  +-(1) mozilla::Compression::LZ4::compress
             :  |
    1.177 ms :  +-(1) free
             :  |
    1.183 ms :  +-(1) moz_arena_malloc

# Function Call Graph for 'firefox' (session: f70d581388175dab)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME   FUNCTION
    3.058  s : (1) firefox
    2.847  s :  +-(82) mozilla::detail::ConditionVariableImpl::wait_for
    2.456  s :  |  +-(50) mozilla::detail::ConditionVariableImpl::wait
    2.454  s :  |  | (49) linux:schedule
             :  |  |
  389.378 ms :  |  +-(32) linux:schedule
             :  |
  209.631 ms :  +-(2) mozilla::detail::ConditionVariableImpl::wait
  209.596 ms :  | (2) linux:schedule
             :  |
    1.628 ms :  +-(1) moz_xmalloc
    1.620 ms :    (1) malloc
    1.583 ms :    (1) linux:schedule
namhyung commented 5 years ago

Hmm.. looks like there's no problem calling strdup(). Maybe it's because of invalid trampoline somehow, but now sure.

honggyukim commented 5 years ago

It seems that strdup is hook by something else.

$ cgdb -q -ex="b mcount-noplt.c:121" -ex="r" --args uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org
...
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (mcount-noplt.c:121) pending.
Starting program: /home/honggyu/work/uftrace/uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
process 872 is executing new program: /usr/lib/firefox/firefox
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[Switching to Thread 0x7ffff7fc4800 (LWP 872)]

Thread 2.1 "firefox" hit Breakpoint 1, mcount_arch_hook_no_plt (elf=<optimized out>, modname=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", offset=93824
992231424) at /home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c:121
115│                 /* update GOT to point the trampoline */
116│                 memcpy((void *)rela->r_offset + offset, &tramp, sizeof(long));
117│
118│                 tramp += TRAMP_ENT_SIZE;
119│         }
120│
121├───────> mprotect(trampoline, tramp_len, PROT_READ|PROT_EXEC);
122│
123│         pd->mod_name = xstrdup(modname);
124│
125│         return pd;
126│ }
/home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c
(gdb) next
121│         mprotect(trampoline, tramp_len, PROT_READ|PROT_EXEC);
122│
123├───────> pd->mod_name = xstrdup(modname);
124│
125│         return pd;
126│ }
/home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c
(gdb) step

(gdb) bt
#0  __GI___strdup (s=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox") at strdup.c:40
#1  0x00007ffff7bc365a in mcount_arch_hook_no_plt (elf=<optimized out>, modname=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", offset=93824992231424) at
 /home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c:123
#2  0x00007ffff7ba953e in find_got (offset=93824992231424, modname=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", iter=0x7fffffffdea0, elf=0x7fffffffdf2
0) at /home/honggyu/work/uftrace/libmcount/plthook.c:196
#3  hook_pltgot (modname=modname@entry=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", offset=offset@entry=93824992231424) at /home/honggyu/work/uftrace/
libmcount/plthook.c:306
#4  0x00007ffff7ba9b39 in setup_exe_plthook_data (info=info@entry=0x7fffffffe000, sz=sz@entry=64, arg=arg@entry=0x7ffff7dd4e00 <exename>) at /home/honggyu/wor
k/uftrace/libmcount/plthook.c:506
#5  0x00007ffff6c4a0e4 in __GI___dl_iterate_phdr (callback=callback@entry=0x7ffff7ba9b00 <setup_exe_plthook_data>, data=data@entry=0x7ffff7dd4e00 <exename>) a
t dl-iteratephdr.c:76
#6  0x00007ffff7ba90e5 in mcount_setup_plthook (exename=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", nest_libcall=<optimized out>) at /home/honggyu/wo
rk/uftrace/libmcount/plthook.c:518
#7  0x00007ffff7ba749c in mcount_startup () at /home/honggyu/work/uftrace/libmcount/mcount.c:1742
#8  0x00007ffff7de76ca in call_init (l=<optimized out>, argc=argc@entry=3, argv=argv@entry=0x7fffffffe268, env=env@entry=0x7fffffffe288) at dl-init.c:72
#9  0x00007ffff7de77db in call_init (env=0x7fffffffe288, argv=0x7fffffffe268, argc=3, l=<optimized out>) at dl-init.c:30
#10 _dl_init (main_map=0x7ffff7ffe168, argc=3, argv=0x7fffffffe268, env=0x7fffffffe288) at dl-init.c:120
#11 0x00007ffff7dd7c6a in _dl_start_user () from /lib64/ld-linux-x86-64.so.2
#12 0x0000000000000003 in ?? ()
#13 0x00007fffffffe54d in ?? ()
#14 0x00007fffffffe566 in ?? ()
#15 0x00007fffffffe571 in ?? ()
#16 0x0000000000000000 in ?? ()
 1│ /* strdup() replacement (from stdwin, if you must know) */
 2│
 3│ #include "pgenheaders.h"
 4│
 5│ char *
 6│ strdup(const char *str)
 7│ {
 8│         if (str != NULL) {
 9│                 register char *copy = malloc(strlen(str) + 1);
10│                 if (copy != NULL)
11│                         return strcpy(copy, str);
12│         }
13│         return NULL;
14├>}
/usr/src/python2.7-2.7.12/Python/strdup.c
(gdb) continue
Continuing.

Thread 2.1 "firefox" received signal SIGSEGV, Segmentation fault.
0x0000000000000000 in ?? ()
honggyukim commented 5 years ago

It seems that strdup internally calls malloc and it goes to plt_hooker, then get crashed.

(gdb) bt
#0  plt_hooker () at /home/honggyu/work/uftrace/arch/x86_64/plthook.S:15
#1  0x000055555556354d in malloc ()
#2  0x00007ffff6b9248a in __GI___strdup (s=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox") at strdup.c:42
#3  0x00007ffff7bc365a in mcount_arch_hook_no_plt (elf=<optimized out>, modname=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", offset=93824992231424) at
 /home/honggyu/work/uftrace/arch/x86_64/mcount-noplt.c:123
#4  0x00007ffff7ba953e in find_got (offset=93824992231424, modname=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", iter=0x7fffffffdea0, elf=0x7fffffffdf2
0) at /home/honggyu/work/uftrace/libmcount/plthook.c:196
#5  hook_pltgot (modname=modname@entry=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", offset=offset@entry=93824992231424) at /home/honggyu/work/uftrace/libmcount/plthook.c:306
#6  0x00007ffff7ba9b39 in setup_exe_plthook_data (info=info@entry=0x7fffffffe000, sz=sz@entry=64, arg=arg@entry=0x7ffff7dd4e00 <exename>) at /home/honggyu/wor
k/uftrace/libmcount/plthook.c:506
#7  0x00007ffff6c4a0e4 in __GI___dl_iterate_phdr (callback=callback@entry=0x7ffff7ba9b00 <setup_exe_plthook_data>, data=data@entry=0x7ffff7dd4e00 <exename>) a
t dl-iteratephdr.c:76
#8  0x00007ffff7ba90e5 in mcount_setup_plthook (exename=0x7ffff7dd4e00 <exename> "/usr/lib/firefox/firefox", nest_libcall=<optimized out>) at /home/honggyu/wo
rk/uftrace/libmcount/plthook.c:518
#9  0x00007ffff7ba749c in mcount_startup () at /home/honggyu/work/uftrace/libmcount/mcount.c:1742
#10 0x00007ffff7de76ca in call_init (l=<optimized out>, argc=argc@entry=3, argv=argv@entry=0x7fffffffe268, env=env@entry=0x7fffffffe288) at dl-init.c:72
#11 0x00007ffff7de77db in call_init (env=0x7fffffffe288, argv=0x7fffffffe268, argc=3, l=<optimized out>) at dl-init.c:30
#12 _dl_init (main_map=0x7ffff7ffe168, argc=3, argv=0x7fffffffe268, env=0x7fffffffe288) at dl-init.c:120
#13 0x00007ffff7dd7c6a in _dl_start_user () from /lib64/ld-linux-x86-64.so.2
#14 0x0000000000000003 in ?? ()
#15 0x00007fffffffe54d in ?? ()
#16 0x00007fffffffe566 in ?? ()
#17 0x00007fffffffe571 in ?? ()
#18 0x0000000000000000 in ?? ()
 1│ Dump of assembler code for function plt_hooker:
 2│    0x00007ffff7bc246a <+0>:     sub    rsp,0x30
 3│    0x00007ffff7bc246e <+4>:     mov    QWORD PTR [rsp+0x28],rdi
 4│    0x00007ffff7bc2473 <+9>:     mov    QWORD PTR [rsp+0x20],rsi
 5│    0x00007ffff7bc2478 <+14>:    mov    QWORD PTR [rsp+0x18],rdx
 6│    0x00007ffff7bc247d <+19>:    mov    QWORD PTR [rsp+0x10],rcx
 7│    0x00007ffff7bc2482 <+24>:    mov    QWORD PTR [rsp+0x8],r8
 8│    0x00007ffff7bc2487 <+29>:    mov    QWORD PTR [rsp],r9
 9│    0x00007ffff7bc248b <+33>:    mov    rdx,QWORD PTR [rsp+0x30]
10│    0x00007ffff7bc2490 <+38>:    mov    rsi,QWORD PTR [rsp+0x38]
11│    0x00007ffff7bc2495 <+43>:    lea    rdi,[rsp+0x40]
12│    0x00007ffff7bc249a <+48>:    mov    rcx,rsp
13│    0x00007ffff7bc249d <+51>:    and    rsp,0xfffffffffffffff0
14│    0x00007ffff7bc24a1 <+55>:    push   rcx
15│    0x00007ffff7bc24a2 <+56>:    push   rax
16│    0x00007ffff7bc24a3 <+57>:    call   0x7ffff7ba9c00 <plthook_entry>
17│    0x00007ffff7bc24a8 <+62>:    mov    r11,rax
18│    0x00007ffff7bc24ab <+65>:    pop    rax
19│    0x00007ffff7bc24ac <+66>:    pop    rcx
20│    0x00007ffff7bc24ad <+67>:    mov    rsp,rcx
21│    0x00007ffff7bc24b0 <+70>:    mov    r9,QWORD PTR [rsp]
22│    0x00007ffff7bc24b4 <+74>:    mov    r8,QWORD PTR [rsp+0x8]
23│    0x00007ffff7bc24b9 <+79>:    mov    rcx,QWORD PTR [rsp+0x10]
24│    0x00007ffff7bc24be <+84>:    mov    rdx,QWORD PTR [rsp+0x18]
25│    0x00007ffff7bc24c3 <+89>:    mov    rsi,QWORD PTR [rsp+0x20]
26│    0x00007ffff7bc24c8 <+94>:    mov    rdi,QWORD PTR [rsp+0x28]
27│    0x00007ffff7bc24cd <+99>:    add    rsp,0x30
28│    0x00007ffff7bc24d1 <+103>:   cmp    r11,0x0
29│    0x00007ffff7bc24d5 <+107>:   cmove  r11,QWORD PTR [rip+0x213ca3]        # 0x7ffff7dd6180 <plthook_resolver_addr>
30│    0x00007ffff7bc24dd <+115>:   je     0x7ffff7bc24e3 <plt_hooker+121>
31│    0x00007ffff7bc24df <+117>:   add    rsp,0x10
32├──> 0x00007ffff7bc24e3 <+121>:   jmp    r11
33│ End of assembler dump.

It gets crashed after that.

honggyukim commented 5 years ago

It works fine in Ubuntu 18.04 machine.

$ cat /etc/os-release | grep "^VERSION="
VERSION="18.04.2 LTS (Bionic Beaver)"

$ uftrace record --force /usr/lib/firefox/firefox --headless https://www.mozilla.org
*** You are running in headless mode.
honggyukim commented 5 years ago

Hmm.. But it shows some "inverted time" messages as follows:

$ uftrace replay
...
   0.059 us [ 27625] | memset();
   0.065 us [ 27625] | pthread_mutex_unlock();
                     |    /* inverted time: broken data? */
            [ 27625] | pthread_mutexattr_init() {
   0.239 us [ 27625] |   pthread_mutex_lock();
   0.107 us [ 27625] |   pthread_mutex_unlock();
                     |      /* inverted time: broken data? */
   0.547 us [ 27625] | } /* pthread_mutexattr_init */
   0.164 us [ 27625] | pthread_mutexattr_settype();
   1.320 us [ 27625] | pthread_mutex_init();
...
honggyukim commented 5 years ago

It shows another problem.

$ uftrace record -la /usr/lib/firefox/firefox --headless https://www.mozilla.org

$ uftrace replay
...
   0.437 us [ 27914] | strncpy(0x7ff01c5e6a00, "66.0.4", 6);
   0.540 us [ 27914] | strlen("66.0.4") = 6;
                     |    /* inverted time: broken data? */
   1.716 us [ 27914] | pthread_mutexattr_init();
   0.580 us [ 27914] | strncpy(0x7ff01c5e6a08, "66.0.4", 6);
   0.323 us [ 27914] | pthread_mutexattr_settype();
            [ 27914] | pthread_mutex_init(&mozilla::sse_private::sse3_enabled, 0x7ffe9bbd32b0) {
   0.727 us [ 27914] |   pthread_WARN: invalid rstack read
mutex_lock(0x7ff01c600018) = 0;
   0.417 us [ 27914] |   memset(0x7ff01c5e6a00, 229, 8);
                     |      /* inverted time: broken data? */
   9.260 us [ 27914] | } = 0; /* pthread_mutex_init */
            [ 27914] | } = 0; /* pthread_mutex_unlock */
   0.280 us [ 27914] | pthread_mutex_lock(0x7ff01c600018) = 0;
            [ 27914] | pthread_mutexattr_destroy() {
   0.357 us [ 27914] |   memset(0x7ff01c5e6a08, 229, 8);
   0.193 us [ 27914] |   pthread_mutexattr_init();
   0.293 us [ 27914] |   pthread_mutex_unlock(0x7ff01c600018) = 0;
   0.204 us [ 27914] |   pthread_mutexattr_settype();
            [ 27914] |   strlen("<FC><D5>^Q^W") {
   1.913 us [ 27920] | pthread_mutex_lock(0x7ff01c600018) = 0;
   0.616 us [ 27920] | pthread_mutex_unlock(0x7ff01c600018) = 0;
   0.616 us [ 27920] | pthread_mutex_lock(0x7ff01c600018) = 0;
...