* [Bug runtime/14659] New: task_finder2 breaks ptrace apps
@ 2012-10-03 1:09 jistone at redhat dot com
2012-10-08 19:06 ` [Bug runtime/14659] " dsmith at redhat dot com
` (5 more replies)
0 siblings, 6 replies; 7+ messages in thread
From: jistone at redhat dot com @ 2012-10-03 1:09 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
Bug #: 14659
Summary: task_finder2 breaks ptrace apps
Product: systemtap
Version: unspecified
Status: NEW
Severity: normal
Priority: P2
Component: runtime
AssignedTo: systemtap@sourceware.org
ReportedBy: jistone@redhat.com
Classification: Unclassified
I'm running on kernel 3.5.4-1.fc17.x86_64, which is utrace-free, thus using
task_finder2. I was trying to debug a problem between stapdyn and its module,
but when certain kernel-mode stap scripts are running, dyninst is completely
disrupted. I can reproduce this with strace too, so I think it's a conflict
with ptrace().
First the good output, then the bad stap runs:
> $ strace -e read true
> read(4, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\30B\273?\0\0\0"..., 832) = 832
> +++ exited with 0 +++
> $ stap -V
> Systemtap translator/driver (version 2.0/0.154, commit release-1.8-311-g44f25c1)
> Copyright (C) 2005-2012 Red Hat, Inc. and others
> This is free software; see the source for copying conditions.
> enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS DYNINST
> $ stap -e 'probe never{print_ubacktrace()}' -c 'strace -e read true'
> --- SIGTRAP {si_signo=SIGTRAP, si_code=0x5, si_pid=9294, si_uid=10719} ---
> --- SIGTRAP {si_signo=SIGTRAP, si_code=SI_KERNEL} ---
> +++ killed by SIGTRAP +++
> Warning: child process exited with signal 5 (Trace/breakpoint trap)
> WARNING: /usr/local/bin/staprun exited with status: 1
> Pass 5: run failed. Try again with another '--vp 00001' option.
> $ stap -e 'probe process.begin{next}' -c 'strace -e read true'
> +++ exited with 0 +++
The same tests work fine on 2.6.32-279.5.2.el6.x86_64, with utrace, which is
why I blamed task_finder2 in the subject. It could also be a bug in any of the
new kernel infrastructure that task_finder2 uses though.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
@ 2012-10-08 19:06 ` dsmith at redhat dot com
2012-10-08 19:26 ` jistone at redhat dot com
` (4 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: dsmith at redhat dot com @ 2012-10-08 19:06 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
David Smith <dsmith at redhat dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |dsmith at redhat dot com
--- Comment #1 from David Smith <dsmith at redhat dot com> 2012-10-08 19:06:29 UTC ---
I've been looking at this one. At first I thought it might be related to
runtime/stp_utrace.c's use of the TASK_TRACED flag, but even without that, the
example in this testcase still failed.
Here's what the testcase breaks down to:
====
# stap -vp2 -e 'probe never{print_ubacktrace()}' -c 'strace -e read true'
Pass 1: parsed user script and 89 library script(s) using
202528virt/22076res/2772shr/19600data kb, in 180usr/50sys/237real ms.
# functions
print_ubacktrace:unknown ()
%{ /* pragma:unwind */ /* pragma:symbols */
/* myproc-unprivileged */ /* pragma:uprobes */ /* pragma:vma */
_stp_stack_user_print(CONTEXT, _STP_SYM_FULL);
%}
# probes
never /* <- never */
print_ubacktrace()
Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 embed(s), 0 global(s)
using 203060virt/22848res/3040shr/20132data kb, in 0usr/0sys/12real ms.
+===
So, the print_ubacktrace() function uses several pragmas. I've narrowed things
down to the following script which gets the same error:
====
# functions
function doit()
%{ /* pragma:vma */
_stp_print("never\n");
%}
# probes
probe never {
doit()
}
====
The vma pragma turns on vma tracking in task_finder2, which turns on syscall
tracing. I'll bet that is what is interfering with ptrace().
When doing syscall tracing, task_finder2 attaches to the 'sys_enter' and
'sys_exit' tracepoints. Setting a handler on those tracepoints sets the
TIF_SYSCALL_TRACEPOINT task flag, which gets checked along with the
TIF_SYSCALL_TRACE task flag (which ptrace uses) in _TIF_WORK_SYSCALL_MASK.
Here's a syscall tracing test that shows similar behavior:
====
# stap -v -e 'probe process.syscall{printf("%d\n", $syscall)}' -c 'strace -e
read true'
Pass 1: parsed user script and 89 library script(s) using
204748virt/22196res/2856shr/19720data kb, in 170usr/50sys/232real ms.
Pass 2: analyzed script: 1 probe(s), 1 function(s), 1 embed(s), 0 global(s)
using 205276virt/22968res/3128shr/20248data kb, in 0usr/0sys/6real ms.
Pass 3: translated to C into
"/tmp/stappzFQd4/stap_31c0780e9dc65829f8476ec5a54fb52b_1254_src.c" using
205276virt/23300res/3432shr/20248data kb, in 0usr/0sys/1real ms.
Pass 4: compiled C into "stap_31c0780e9dc65829f8476ec5a54fb52b_1254.ko" in
2940usr/1620sys/5112real ms.
Pass 5: starting run.
--- SIGTRAP {si_signo=SIGTRAP, si_code=0x5, si_pid=12793, si_uid=5183} ---
--- SIGTRAP {si_signo=SIGTRAP, si_code=SI_KERNEL} ---
+++ killed by SIGTRAP (core dumped) +++
Warning: child process exited with signal 5 (Trace/breakpoint trap)
15
13
14
59
59
59
59
12
9
21
2
5
9
3
2
0
5
9
10
9
9
3
9
9
158
10
10
10
11
13
39
63
12
12
12
102
104
56
61
101
101
61
101
61
62
101
61
101
101
61
101
61
231
4
4
4
4
4
56
13
13
13
13
13
13
13
14
14
14
61
101
14
101
101
1
101
14
61
14
101
1
101
14
61
14
1
160
13
234
WARNING: /usr/local/bin/staprun exited with status: 1
Pass 5: run completed in 20usr/220sys/703real ms.
Pass 5: run failed. Try again with another '--vp 00001' option.
====
I'll think about ways to avoid syscall tracing when doing vma tracking.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
2012-10-08 19:06 ` [Bug runtime/14659] " dsmith at redhat dot com
@ 2012-10-08 19:26 ` jistone at redhat dot com
2012-10-08 20:43 ` dsmith at redhat dot com
` (3 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: jistone at redhat dot com @ 2012-10-08 19:26 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
--- Comment #2 from Josh Stone <jistone at redhat dot com> 2012-10-08 19:26:18 UTC ---
(In reply to comment #1)
> The vma pragma turns on vma tracking in task_finder2, which turns on syscall
> tracing. I'll bet that is what is interfering with ptrace().
>
> When doing syscall tracing, task_finder2 attaches to the 'sys_enter' and
> 'sys_exit' tracepoints. Setting a handler on those tracepoints sets the
> TIF_SYSCALL_TRACEPOINT task flag, which gets checked along with the
> TIF_SYSCALL_TRACE task flag (which ptrace uses) in _TIF_WORK_SYSCALL_MASK.
I'm skeptical of this root cause, because syscall tracepoints don't cause any
problem with perf:
$ perf record -e raw_syscalls:sys_* strace -e read true
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\30\242b<\0\0\0"...,
832) = 832
+++ exited with 0 +++
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.088 MB perf.data (~3830 samples) ]
Actually, even stap is fine on the raw tracepoints:
$ stap eventcount.stp 'kernel.trace("sys_enter")' \
'kernel.trace("sys_exit")' -c 'strace -e read true'
read(4, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\30\242b<\0\0\0"...,
832) = 832
+++ exited with 0 +++
Starting event counting at Mon Oct 8 12:24:46 2012 PDT, pid 27963 + children
Finished event counting at Mon Oct 8 12:24:47 2012 PDT.
Total time elapsed: 34 ms, 760 events total, 686 after filtering.
TID EVENT COUNT (RATE Hz)
--- ----- ---------------
stapio(27963) kernel.trace("sys_enter") 7 (205.88)
stapio(27963) kernel.trace("sys_exit") 7 (205.88)
strace(27963) kernel.trace("sys_enter") 305 (8970.58)
strace(27963) kernel.trace("sys_exit") 305 (8970.58)
strace(27966) kernel.trace("sys_exit") 3 (88.23)
strace(27966) kernel.trace("sys_enter") 3 (88.23)
strace(27967) kernel.trace("sys_exit") 5 (147.05)
strace(27967) kernel.trace("sys_enter") 5 (147.05)
true(27967) kernel.trace("sys_exit") 23 (676.47)
true(27967) kernel.trace("sys_enter") 23 (676.47)
> I'll think about ways to avoid syscall tracing when doing vma tracking.
If there's really a problem between the kernel's syscall tracing and ptrace,
then we should report this as a kernel bug. But right now, it seems like
there's more going on...
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
2012-10-08 19:06 ` [Bug runtime/14659] " dsmith at redhat dot com
2012-10-08 19:26 ` jistone at redhat dot com
@ 2012-10-08 20:43 ` dsmith at redhat dot com
2012-10-08 21:03 ` dsmith at redhat dot com
` (2 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: dsmith at redhat dot com @ 2012-10-08 20:43 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
--- Comment #3 from David Smith <dsmith at redhat dot com> 2012-10-08 20:42:33 UTC ---
(In reply to comment #2)
> If there's really a problem between the kernel's syscall tracing and ptrace,
> then we should report this as a kernel bug. But right now, it seems like
> there's more going on...
Looks like you are right that it isn't syscall probing directly.
Looking back at the test script I posted earlier:
====
# functions
function doit()
%{ /* pragma:vma */
_stp_print("never\n");
%}
# probes
probe never {
doit()
}
====
That script causes the bad SIGTRAP behavior. However, if I stub out
_stp_vma_init() and _stp_vma_done() I don't see the SIGTRAPs.
So, it isn't the syscall tracing in the vma tracking stuff, but it is something
else that the vma tracking does.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
` (2 preceding siblings ...)
2012-10-08 20:43 ` dsmith at redhat dot com
@ 2012-10-08 21:03 ` dsmith at redhat dot com
2012-10-11 15:58 ` dsmith at redhat dot com
2012-10-11 22:30 ` agentzh at gmail dot com
5 siblings, 0 replies; 7+ messages in thread
From: dsmith at redhat dot com @ 2012-10-08 21:03 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
--- Comment #4 from David Smith <dsmith at redhat dot com> 2012-10-08 21:02:41 UTC ---
(In reply to comment #3)
> (In reply to comment #2)
> > If there's really a problem between the kernel's syscall tracing and ptrace,
> > then we should report this as a kernel bug. But right now, it seems like
> > there's more going on...
>
> Looks like you are right that it isn't syscall probing directly.
>
> Looking back at the test script I posted earlier:
>
> ====
> # functions
> function doit()
> %{ /* pragma:vma */
>
> _stp_print("never\n");
> %}
>
> # probes
> probe never {
> doit()
> }
> ====
>
> That script causes the bad SIGTRAP behavior. However, if I stub out
> _stp_vma_init() and _stp_vma_done() I don't see the SIGTRAPs.
>
> So, it isn't the syscall tracing in the vma tracking stuff, but it is something
> else that the vma tracking does.
After poking this a bit more, it could be that stubbing out _stp_vma_init()
also removes the only task_finder client, so it doesn't do anything.
I get the following output with a simple process.begin probe:
===
stap -e 'probe process.begin { printf("%s\n", execname()) }' -c 'strace -e read
true'
+++ exited with 0 +++
stapio
strace
strace
strace
true
===
Here we don't get the SIGTRAP, but we don't get strace's output either.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
` (3 preceding siblings ...)
2012-10-08 21:03 ` dsmith at redhat dot com
@ 2012-10-11 15:58 ` dsmith at redhat dot com
2012-10-11 22:30 ` agentzh at gmail dot com
5 siblings, 0 replies; 7+ messages in thread
From: dsmith at redhat dot com @ 2012-10-11 15:58 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
David Smith <dsmith at redhat dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution| |FIXED
--- Comment #5 from David Smith <dsmith at redhat dot com> 2012-10-11 15:58:04 UTC ---
Commit c551686 fixes this problem (and adds a testcase).
Oleg Nesterov figured out that stp_utrace.c was using TIF_SYSCALL_TRACE when it
shouldn't.
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
* [Bug runtime/14659] task_finder2 breaks ptrace apps
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
` (4 preceding siblings ...)
2012-10-11 15:58 ` dsmith at redhat dot com
@ 2012-10-11 22:30 ` agentzh at gmail dot com
5 siblings, 0 replies; 7+ messages in thread
From: agentzh at gmail dot com @ 2012-10-11 22:30 UTC (permalink / raw)
To: systemtap
http://sourceware.org/bugzilla/show_bug.cgi?id=14659
agentzh <agentzh at gmail dot com> changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |agentzh at gmail dot com
--- Comment #6 from agentzh <agentzh at gmail dot com> 2012-10-11 22:29:58 UTC ---
*** Bug 14537 has been marked as a duplicate of this bug. ***
--
Configure bugmail: http://sourceware.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2012-10-11 22:30 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-10-03 1:09 [Bug runtime/14659] New: task_finder2 breaks ptrace apps jistone at redhat dot com
2012-10-08 19:06 ` [Bug runtime/14659] " dsmith at redhat dot com
2012-10-08 19:26 ` jistone at redhat dot com
2012-10-08 20:43 ` dsmith at redhat dot com
2012-10-08 21:03 ` dsmith at redhat dot com
2012-10-11 15:58 ` dsmith at redhat dot com
2012-10-11 22:30 ` agentzh at gmail dot com
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).