From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 12803 invoked by alias); 8 Jun 2018 22:01:55 -0000 Mailing-List: contact systemtap-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Post: List-Help: , Sender: systemtap-owner@sourceware.org Received: (qmail 12715 invoked by uid 48); 8 Jun 2018 22:01:47 -0000 From: "awillia2 at sourcefire dot com" To: systemtap@sourceware.org Subject: [Bug kprobes/23260] SystemTap usage appears to adversely affect GDB breakpoint functionality Date: Fri, 08 Jun 2018 22:01:00 -0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: changed X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: systemtap X-Bugzilla-Component: kprobes X-Bugzilla-Version: unspecified X-Bugzilla-Keywords: X-Bugzilla-Severity: normal X-Bugzilla-Who: awillia2 at sourcefire dot com X-Bugzilla-Status: UNCONFIRMED X-Bugzilla-Resolution: X-Bugzilla-Priority: P2 X-Bugzilla-Assigned-To: systemtap at sourceware dot org X-Bugzilla-Target-Milestone: --- X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: Message-ID: In-Reply-To: References: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: http://sourceware.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-SW-Source: 2018-q2/txt/msg00097.txt.bz2 https://sourceware.org/bugzilla/show_bug.cgi?id=3D23260 --- Comment #3 from awillia2 at sourcefire dot com --- I wasn't able to get the stap2perf working correctly with the strace.stp script, but I did run "sudo perf record -e 'syscalls:sys_enter_*' -p " while gdb was stopped at the breakpoint, and running 'continue' afterward, the hello-world program finished successfully. Also,= I confirmed that running stap with -DALIBI did not prevent the issue from occurring. I did some more debugging with https://sourceware.org/systemtap/examples/process/sigmon.stp (with the if condition removed) and also found a way to reproduce the second issue descr= ibed above (using a 64-bit build of the hello-world program this time): $ gdb ./hello-world GNU gdb (Ubuntu 8.0.1-0ubuntu1) 8.0.1 [ ... ] (gdb) info files Symbols from "/home/zelda/Desktop/hello-world". Local exec file: `/home/zelda/Desktop/hello-world', file type elf64-x86-64. Entry point: 0x44e370 0x0000000000401000 - 0x000000000047b8ab is .text 0x000000000047c000 - 0x00000000004afd75 is .rodata 0x00000000004afea0 - 0x00000000004b09dc is .typelink 0x00000000004b09e0 - 0x00000000004b0a18 is .itablink 0x00000000004b0a18 - 0x00000000004b0a18 is .gosymtab 0x00000000004b0a20 - 0x00000000004f53b3 is .gopclntab 0x00000000004f6000 - 0x00000000004f84c8 is .noptrdata 0x00000000004f84e0 - 0x00000000004fa1f0 is .data 0x00000000004fa200 - 0x0000000000514b08 is .bss 0x0000000000514b20 - 0x00000000005191c0 is .noptrbss 0x0000000000400fc8 - 0x0000000000401000 is .note.go.buildid (gdb) break *0x44e370 Breakpoint 1 at 0x44e370: file /usr/lib/go-1.8/src/runtime/rt0_linux_amd64.= s, line 8. (gdb) run Starting program: /home/zelda/Desktop/hello-world=20 Breakpoint 1, _rt0_amd64_linux () at /usr/lib/go-1.8/src/runtime/rt0_linux_amd64.s:8 8 LEAQ 8(SP), SI // argv (gdb) [ In a second terminal: ] $ ps -eL -o pid,ppid,lwp,stat,nlwp,cmd | awk 'NR=3D=3D1 || /\/home\/zelda\/Desktop\/hello-world/' PID PPID LWP STAT NLWP CMD 49663 49118 49663 t 1 /home/zelda/Desktop/hello-world [ In a third terminal: ] $ sudo stap --suppress-handler-errors --skip-badvars strace.stp -x 49663 -v Pass 1: parsed user script and 465 library scripts using 119616virt/48792res/6676shr/42428data kb, in 100usr/50sys/181real ms. Pass 2: analyzed script: 1116 probes, 207 functions, 104 embeds, 108 globals using 311348virt/241716res/7876shr/234160data kb, in 23180usr/850sys/25056r= eal ms. Pass 3: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.c Pass 4: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.ko Pass 5: starting run. Fri Jun 8 20:59:17 2018.167252 arch_prctl(ARCH_SET_FS, 5222056) =3D 0 Fri Jun 8 20:59:17 2018.168042 sched_getaffinity(0, 8192, 0x7fffffffc078) = =3D 16 Fri Jun 8 20:59:17 2018.168409 mmap2(0xc000000000, 65536, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0xc000000000 Fri Jun 8 20:59:17 2018.168421 munmap(0xc000000000, 65536) =3D 0 Fri Jun 8 20:59:17 2018.168445 mmap2(0x0, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0x7ffff7fba000 Fri Jun 8 20:59:17 2018.168604 mmap2(0xc420000000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0xc420000000 Fri Jun 8 20:59:17 2018.168613 mmap2(0xc41fff8000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0xc41fff8000 Fri Jun 8 20:59:17 2018.168618 mmap2(0xc000000000, 4096, PROT_READ|PROT_WR= ITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0xc000000000 Fri Jun 8 20:59:17 2018.168622 mmap2(0x0, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0x7ffff7faa000 Fri Jun 8 20:59:17 2018.168642 mmap2(0x0, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =3D 0x7ffff7f9a000 Fri Jun 8 20:59:17 2018.168923 rt_sigprocmask(SIG_SETMASK, NULL, 0x4fae98,= 8) =3D 0 Fri Jun 8 20:59:17 2018.169039 sigaltstack(0x0, 0x7fffffffe010) =3D 0 Fri Jun 8 20:59:17 2018.169046 sigaltstack({ss_sp=3D0xc420002000, ss_flags= =3D0x0, ss_size=3D32672}, 0x0) =3D 0 Fri Jun 8 20:59:17 2018.169052 rt_sigprocmask(SIG_SETMASK, [EMPTY], 0x0, 8= ) =3D 0 Fri Jun 8 20:59:17 2018.169056 gettid() =3D 49663 Fri Jun 8 20:59:17 2018.169063 rt_sigaction(SIGHUP, {NULL}, 0x7fffffffdfe8= , 8) =3D 0 Fri Jun 8 20:59:17 2018.169081 rt_sigaction(SIGHUP, {0x44e6f0, SA_ONSTACK|SA_RESTART|SA_SIGINFO|SA_RESTORER, 0x44e820, [SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGBUS|SIGFPE|SIGKILL|SIGUSR1= |SIGSEGV|SIGPIPE|SIGUSR2|SIGALRM|SIGTERM|SIGCHLD|SIGCONT|SIGSTOP|SIGTSTP|SI= GTTIN|SIGTTOU|SIGURG|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGIO/SIGPO= LL|SIGPWR|SIGSYS]}, 0x0, 8) =3D 0 [ ... ] Fri Jun 8 20:59:17 2018.169864 rt_sigaction(0x40, {NULL}, 0x7fffffffdfe8, = 8) =3D 0 Fri Jun 8 20:59:17 2018.169874 rt_sigaction(0x40, {0x44e6f0, SA_ONSTACK|SA_RESTART|SA_SIGINFO|SA_RESTORER, 0x44e820, [SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGBUS|SIGFPE|SIGKILL|SIGUSR1= |SIGSEGV|SIGPIPE|SIGUSR2|SIGALRM|SIGTERM|SIGCHLD|SIGCONT|SIGSTOP|SIGTSTP|SI= GTTIN|SIGTTOU|SIGURG|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGIO/SIGPO= LL|SIGPWR|SIGSYS]}, 0x0, 8) =3D 0 Fri Jun 8 20:59:17 2018.169897 rt_sigprocmask(SIG_SETMASK, [SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGBUS|SIGFPE|SIGKILL|SIGUSR1= |SIGSEGV|SIGPIPE|SIGUSR2|SIGALRM|SIGTERM|SIGCHLD|SIGCONT|SIGSTOP|SIGTSTP|SI= GTTIN|SIGTTOU|SIGURG|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGIO/SIGPO= LL|SIGPWR|SIGSYS], 0x7fffffffdfb8, 8) =3D 0 [ Printed by sigmon.stp when strace.stp starts: ] SPID SNAME RPID RNAME SIGNUM SIGNAME=20=20=20=20= =20=20=20=20=20 ... 49663 hello-world 49118 gdb 17 SIGCHLD=20=20=20=20= =20=20=20=20=20 49663 hello-world 49118 gdb 17 SIGCHLD=20=20=20=20= =20=20=20=20=20 [ In the second terminal, notice the new LWP: ] $ ps -eL -o pid,ppid,lwp,stat,nlwp,cmd | awk 'NR=3D=3D1 || /\/home\/zelda\/Desktop\/hello-world/' PID PPID LWP STAT NLWP CMD 49663 49118 49663 tl 2 /home/zelda/Desktop/hello-world 49663 49118 49672 tl 2 /home/zelda/Desktop/hello-world [ In the third terminal, Control-C the running stap and rerun: ] $ sudo stap --suppress-handler-errors --skip-badvars strace.stp -x 49663 -v Pass 1: parsed user script and 465 library scripts using 119616virt/48708res/6588shr/42428data kb, in 90usr/50sys/180real ms. Pass 2: analyzed script: 1116 probes, 207 functions, 104 embeds, 108 globals using 311348virt/241568res/7720shr/234160data kb, in 21960usr/880sys/24094r= eal ms. Pass 3: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.c Pass 4: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.ko Pass 5: starting run. Fri Jun 8 21:01:52 2018.772129 rt_sigprocmask(SIG_SETMASK, [EMPTY], 0x0, 8= ) =3D 0 Fri Jun 8 21:01:52 2018.773622 rt_sigprocmask(SIG_SETMASK, [SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGBUS|SIGFPE|SIGKILL|SIGUSR1= |SIGSEGV|SIGPIPE|SIGUSR2|SIGALRM|SIGTERM|SIGCHLD|SIGCONT|SIGSTOP|SIGTSTP|SI= GTTIN|SIGTTOU|SIGURG|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGIO/SIGPO= LL|SIGPWR|SIGSYS], 0x7fffffffdee8, 8) =3D 0 [ Printed again by sigmon.stp: ] SPID SNAME RPID RNAME SIGNUM SIGNAME=20=20=20=20= =20=20=20=20=20 ... 49663 hello-world 49118 gdb 17 SIGCHLD=20=20=20=20= =20=20=20=20=20 49663 hello-world 49118 gdb 17 SIGCHLD=20=20=20=20= =20=20=20 [ In the second terminal, notice the new LWP: ] $ ps -eL -o pid,ppid,lwp,stat,nlwp,cmd | awk 'NR=3D=3D1 || /\/home\/zelda\/Desktop\/hello-world/' PID PPID LWP STAT NLWP CMD 49663 49118 49663 tl 3 /home/zelda/Desktop/hello-world 49663 49118 49672 tl 3 /home/zelda/Desktop/hello-world 49663 49118 49691 tl 3 /home/zelda/Desktop/hello-world [ In the third terminal, Control-C the running stap and rerun: ] zelda@hyrule:~/Desktop$ sudo stap --suppress-handler-errors --skip-badvars strace.stp -x 49663 -v Pass 1: parsed user script and 465 library scripts using 119612virt/48624res/6504shr/42424data kb, in 90usr/60sys/181real ms. Pass 2: analyzed script: 1116 probes, 207 functions, 104 embeds, 108 globals using 311344virt/241252res/7408shr/234156data kb, in 22270usr/910sys/27506r= eal ms. Pass 3: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.c Pass 4: using cached /home/zelda/.systemtap/cache/02/stap_027e862ab47a5cdf6a07ae0b1c596ae7_10797= 24.ko Pass 5: starting run. Fri Jun 8 21:04:54 2018.291180 rt_sigprocmask(SIG_SETMASK, [EMPTY], 0x0, 8= ) =3D 0 [ sigmon.stp indicates that no signals were sent to GDB ] [ In the second terminal, notice the STAT change to the first process: ] $ ps -eL -o pid,ppid,lwp,stat,nlwp,cmd | awk 'NR=3D=3D1 || /\/home\/zelda\/Desktop\/hello-world/' PID PPID LWP STAT NLWP CMD 49663 49118 49663 Sl 3 /home/zelda/Desktop/hello-world 49663 49118 49672 tl 3 /home/zelda/Desktop/hello-world 49663 49118 49691 tl 3 /home/zelda/Desktop/hello-world [ In the original terminal running gdb: ] (gdb) c Continuing. Warning: Cannot insert breakpoint 1. Cannot access memory at address 0x44e370 Command aborted. (gdb)=20 One other thing worth mentioning is that I ran strace.stp against the gdb process itself as well, and when stopped at the breakpoint and strace.stp r= uns for the first time against the child process, the following output is obser= ved: Fri Jun 8 19:22:23 2018.502985 rt_sigreturn() =3D -4 (EINTR) Fri Jun 8 19:22:23 2018.502995 rt_sigreturn() =3D -4 (EINTR) Fri Jun 8 19:22:23 2018.503581 read(5, 0x7fff65f9e207, 1) =3D -11 (EAGAIN) Fri Jun 8 19:22:23 2018.503781 poll(0x56433c570cb0, 4, 0) =3D 0 Fri Jun 8 19:22:23 2018.503793 poll(0x56433c570cb0, 4, -1) =3D 1 This seems odd, since the rt_sigreturn man page indicates that the function doesn't return. --=20 You are receiving this mail because: You are the assignee for the bug.