Bug #2551
closedjstack may deal in stale ustack helper frames
100%
Description
While debugging a couple of issues in the dtrace test suite I've happened upon a bug where ustack helper data may be passed to consumers despite being stale.
This tends to manifest itself as helper frames in inappropriate stacks (completely).
A bit of D such as:
syscall:::entry { @[jstack()] = count(); } tick-5s { exit(0); }
Will produce output like this:
... libc.so.1`syscall+0x5 libc.so.1`thr_sigsetmask+0x1c2 libc.so.1`sigprocmask+0x52 sshd`collect_children+0x2a sshd`server_loop2+0x195 sshd`do_authenticated2+0xc sshd`do_authenticated+0x31 sshd`main+0x14c4 [ /usr/lib/python2.6/threading.py:256 (wait) ] sshd`_start+0x83 126 ...
Which is clearly bogus.
What's happening is that the string buffer used for helper annotations is not cleared in the DTrace buffer, such that subsequent stack invocations, if they are as deep as, or deeper than, a prior annotated stack, will acquire the annotations erroneously.
In this case the actual stack that should have the annotations is
libc.so.1`__pollsys+0x7 libc.so.1`pselect+0x1bf libc.so.1`select+0x8e time.so`floatsleep+0xd8 time.so`time_sleep+0x4a libpython2.6.so.1.0`PyCFunction_Call+0x19d libpython2.6.so.1.0`call_function+0x3e6 libpython2.6.so.1.0`PyEval_EvalFrameEx+0x2cdb [ /usr/lib/python2.6/threading.py:256 (wait) ] libpython2.6.so.1.0`PyEval_EvalCodeEx+0x8cb libpython2.6.so.1.0`fast_function+0x174 libpython2.6.so.1.0`call_function+0xe4 libpython2.6.so.1.0`PyEval_EvalFrameEx+0x2cdb [ /usr/lib/python2.6/Queue.py:177 (get) ] ...
Note that the (wait) annotation is in the 8th frame in both cases, this pattern repeats throughout the entire output.
You can narrow it in time by aggregating on timestamp as well as jstack(), which happens to cause an ordering in time which shows that the bogus entries always postdate a valid stack with helped frames at matching depths.
We need to clear any string space in the DTrace buffer if we process a jstack() or ustack() action and we have string space but no helpers.
Updated by Rich Lowe about 11 years ago
- Subject changed from jstack may deal in stale ustack helpers to jstack may deal in stale ustack helper frames
Updated by Rich Lowe about 11 years ago
- Status changed from In Progress to Resolved
- % Done changed from 0 to 100
- Tags deleted (
needs-triage)
Resolved in r13666 commit:ab986bc53f59