[Bug uprobes/15972] New: core dump with process probes

[Bug uprobes/15972] New: core dump with process probes

[mjw at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

            Bug ID: 15972
           Summary: core dump with process probes
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: uprobes
          Assignee: systemtap at sourceware dot org
          Reporter: mjw at redhat dot com

Linux version 3.10.11-200.fc19.x86_64
(mockbuild@bkernel01.phx2.fedoraproject.org) (gcc version 4.8.1 20130603 (Red
Hat 4.8.1-1) (GCC) ) #1 SMP Mon Sep 9 13:03:01 UTC 2013
Command line: BOOT_IMAGE=/vmlinuz-3.10.11-200.fc19.x86_64
root=UUID=4f86948d-fc04-4940-8f90-e55ac67bf69c ro rd.md=0 rd.lvm=0 rd.dm=0
rd.luks=0 vconsole.keymap=us rhgb quiet LANG=en_US.UTF-8

$ stap -k -v -e 'probe
process("/usr/lib64/libglib-2.0*").function("g_main_context_iterate*").call {
printf("%d %s call\n", pid(), execname()); }'
Pass 1: parsed user script and 106 library script(s) using
226392virt/41848res/3112shr/39532data kb, in 220usr/20sys/820real ms.
Pass 2: analyzed script: 2 probe(s), 2 function(s), 2 embed(s), 0 global(s)
using 387808virt/49920res/5456shr/45028data kb, in 80usr/550sys/9568real ms.
Pass 3: translated to C into "/tmp/stapYViNMv/stap_1284_src.c" using
385332virt/49760res/5416shr/45028data kb, in 20usr/50sys/65real ms.
Pass 4: compiled C into "stap_1284.ko" in 1750usr/350sys/4873real ms.
Pass 5: starting run.
318 accounts-daemon call
318 accounts-daemon call
1123 gdbus call
1123 gdbus call
1056 upowerd call
1056 upowerd call
306 firewalld call
306 firewalld call
958 gdbus call
958 gdbus call
935 gdbus call
935 gdbus call
396 modem-manager call
396 modem-manager call
368 NetworkManager call
368 NetworkManager call
971 gnome-session call
971 gnome-session call
360 polkitd call
360 polkitd call
1034 gdbus call
1034 gdbus call
1046 gdbus call
1046 gdbus call
1125 gdbus call
1125 gdbus call
920 gdm call
920 gdm call
1026 gdbus call
1026 gdbus call
1161 gdbus call
1161 gdbus call
1516 gdbus call
1516 gdbus call
1522 gdbus call
1522 gdbus call
1526 gdm call
1526 gdm call
1530 gdbus call
1530 gdbus call
1534 gdbus call
1534 gdbus call

<... then some processes start to core dump ...>

dmesg output:

[  182.717920] Kprobes globally unoptimized
[  182.719609] stap_1482: module verification failed: signature and/or required
key missing - tainting kernel
[  182.757338] stap_1482: systemtap: 2.3/0.156, base: ffffffffa032c000, memory:
58data/40text/8ctx/2058net/33alloc kb, probes: 2
[  183.730127] traps: accounts-daemon[318] general protection ip:7fffffffe080
sp:7fff37c523e0 error:0
[  184.471758] traps: gdbus[1137] general protection ip:7fffffffe080
sp:7f6d92cf4bc0 error:0
[  184.471932] traps: upowerd[1056] general protection ip:7fffffffe080
sp:7fff932351b0 error:0
[  184.472203] traps: firewalld[306] general protection ip:7fffffffe080
sp:7fff80710490 error:0
[  184.472461] traps: gdbus[959] general protection ip:7fffffffe080
sp:7f3fa84ead80 error:0
[  184.473344] traps: gdbus[936] general protection ip:7fffffffe080
sp:7fc9319b9dc0 error:0
[  184.473416] traps: modem-manager[396] general protection ip:7fffffffe080
sp:7fffbd866d50 error:0
[  184.473447] Pid 396(modem-manager) over core_pipe_limit
[  184.473448] Skipping core dump
[  184.474172] traps: NetworkManager[368] general protection ip:7fffffffe080
sp:7fff0a3f65f0 error:0
[  184.474200] Pid 368(NetworkManager) over core_pipe_limit
[  184.474201] Skipping core dump
[  184.474808] traps: gnome-session[971] general protection ip:7fffffffe080
sp:7fff4f9c4bf0 error:0
[  184.475138] Pid 971(gnome-session) over core_pipe_limit
[  184.475140] Skipping core dump
[  184.476604] Pid 1034(gdbus) over core_pipe_limit
[  184.476606] Skipping core dump
[  184.477161] Pid 1046(gdbus) over core_pipe_limit
[  184.477162] Skipping core dump
[  184.481080] Pid 1125(gdbus) over core_pipe_limit
[  184.481083] Skipping core dump

All general protection ip addresses look the same.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[mjw at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #1 from Mark Wielaard <mjw at redhat dot com> ---
Tried the same with --dyninst, but that never triggered the probe.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[mjw at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #2 from Mark Wielaard <mjw at redhat dot com> ---
Attaching gdb at the same time shows:

Program received signal SIGSEGV, Segmentation fault.
g_main_context_iterate (context=0x7f7f123a7d80, block=block@entry=1, 
    dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3649
3649      UNLOCK_CONTEXT (context);
(gdb) disassemble 
Dump of assembler code for function g_main_context_iterate:
   0x00007f7f1129ef90 <+0>:    push   %r15
   0x00007f7f1129ef92 <+2>:    push   %r14
   0x00007f7f1129ef94 <+4>:    mov    %esi,%r14d
   0x00007f7f1129ef97 <+7>:    push   %r13
   0x00007f7f1129ef99 <+9>:    push   %r12
   0x00007f7f1129ef9b <+11>:    push   %rbp
   0x00007f7f1129ef9c <+12>:    push   %rbx
   0x00007f7f1129ef9d <+13>:    mov    %rdi,%rbx
   0x00007f7f1129efa0 <+16>:    sub    $0x28,%rsp
   0x00007f7f1129efa4 <+20>:    mov    %edx,0xc(%rsp)
=> 0x00007f7f1129efa8 <+24>:    int3   
   0x00007f7f1129efa9 <+25>:    retq   
   0x00007f7f1129efaa <+26>:    repnz add (%rax),%eax
   0x00007f7f1129efad <+29>:    mov    %rbx,%rdi
   0x00007f7f1129efb0 <+32>:    callq  0x7f7f1129e220 <g_main_context_acquire>

I am surprised gdb sees the int3. And that it gets a SIGSEGV here (not a
SIGTRAP).

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[mjw at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #3 from Mark Wielaard <mjw at redhat dot com> ---
The same disassamble before for stap starts tracing:

Dump of assembler code for function g_main_context_iterate:
   0x00007f9476e8df90 <+0>:    push   %r15
   0x00007f9476e8df92 <+2>:    push   %r14
   0x00007f9476e8df94 <+4>:    mov    %esi,%r14d
   0x00007f9476e8df97 <+7>:    push   %r13
   0x00007f9476e8df99 <+9>:    push   %r12
   0x00007f9476e8df9b <+11>:    push   %rbp
   0x00007f9476e8df9c <+12>:    push   %rbx
   0x00007f9476e8df9d <+13>:    mov    %rdi,%rbx
   0x00007f9476e8dfa0 <+16>:    sub    $0x28,%rsp
   0x00007f9476e8dfa4 <+20>:    mov    %edx,0xc(%rsp)
   0x00007f9476e8dfa8 <+24>:    callq  0x7f9476ecd270 <g_mutex_unlock>
   0x00007f9476e8dfad <+29>:    mov    %rbx,%rdi
   0x00007f9476e8dfb0 <+32>:    callq  0x7f9476e8d220 <g_main_context_acquire>

So the int3 is placed on:
0x00007f9476e8dfa8 <+24>:    callq  0x7f9476ecd270 <g_mutex_unlock>

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[mjw at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #4 from Mark Wielaard <mjw at redhat dot com> ---
Just looking whether this is stap or uprobes or ...?

Lets extract the address we use from the library:

$ objdump -t /usr/lib/debug/usr/lib64/libglib-2.0.so.0.3600.3.debug | grep
g_main_context_iterate
0000000000047f90 l     F .text    00000000000001ef
g_main_context_iterate.isra.22

stap seems to use an address slightly after the start (skips the prologue of
the function): 47f90+18 = 47FA8

So put that into the raw uprobes/perf tracer thingy:

# echo "p:func_entry /usr/lib64/libglib-2.0.so.0.3600.3:0x0000000000047fa8" >>
/sys/kernel/debug/tracing/uprobe_events

And enable the tracer:

# echo 1 > /sys/kernel/debug/tracing/events/uprobes/enable

Oops, crashing processes... in dmesg:

[ 8241.097226] traps: gnome-shell[1114] general protection ip:7fffffffe080
sp:7fff9630b460 error:0
[ 8241.098619] traps: accounts-daemon[328] general protection ip:7fffffffe080
sp:7fffc4235b50 error:0
[ 8241.325253] traps: gdbus[962] general protection ip:7fffffffe080
sp:7f928e88cd80 error:0
[ 8241.325310] traps: gdbus[939] general protection ip:7fffffffe080
sp:7f4c90f6fdc0 error:0
[ 8241.325384] traps: upowerd[1056] general protection ip:7fffffffe080
sp:7fffd4bb5100 error:0
[ 8241.325525] traps: gdbus[364] general protection ip:7fffffffe080
sp:7f3e10d2fd80 error:0
[ 8241.325811] traps: modem-manager[396] general protection ip:7fffffffe080
sp:7fff383892b0 error:0
[ 8241.325900] traps: firewalld[312] general protection ip:7fffffffe080
sp:7fffeed136c0 error:0
[ 8241.326391] traps: gdbus[381] general protection ip:7fffffffe080
sp:7fcc07881d80 error:0

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |SUSPENDED
                 CC|                            |fche at redhat dot com

--- Comment #5 from Frank Ch. Eigler <fche at redhat dot com> ---
kernel bug, reported to some RH kernel uprobes folks

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[jistone at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #6 from Josh Stone <jistone at redhat dot com> ---
(In reply to Mark Wielaard from comment #2)
> I am surprised gdb sees the int3.

I'm not surprised.  The int3 can't be hidden from the process itself, of
course, since it needs to be executed.  Hiding from gdb would require uprobes
to intercept and fake the ptrace peek, which I suppose is possible, but
questionable.

> And that it gets a SIGSEGV here (not a SIGTRAP).

If uprobes is trying to send IP to 7fffffffe080, as dmesg suggests, and if that
doesn't exist, then a SIGSEGV is perfectly reasonable.  I expect that address
is supposed to be where the out-of-line instruction copy lives.

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

--- Comment #7 from Frank Ch. Eigler <fche at redhat dot com> ---
https://bugzilla.redhat.com/show_bug.cgi?id=1073627

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |c.bezemer at tudelft dot nl

--- Comment #8 from Frank Ch. Eigler <fche at redhat dot com> ---
*** Bug 16662 has been marked as a duplicate of this bug. ***

-- 
You are receiving this mail because:
You are the assignee for the bug.

[Bug uprobes/15972] core dump with process probes

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=15972

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|SUSPENDED                   |RESOLVED
         Resolution|---                         |FIXED

--- Comment #9 from Frank Ch. Eigler <fche at redhat dot com> ---
upstream kernel fixes in u[ret]probes should have corrected this particular
report.  uretprobes still fights and loses against longjmp though.

-- 
You are receiving this mail because:
You are the assignee for the bug.