I originally posted this at http://dtrace.org/blogs/brendan/2011/02/16/dtrace-pid-provider-instructions.
The intent of this series of pid provider posts is to share my real-world experience in using the DTrace pid provider and its various features. Here I'll discuss another pid provider topic: the instruction offset probe.
Instruction Offset Probe
The instruction offset probe allows individual instructions to be traced. In my post about the pid provider return probe, the return instruction offset was visible as arg0, providing a hint at the code path taken. This could also be determined by tracing other sub-functions, or examining entry arguments and inspecting the source code. However, by using the instruction offset probe we can directly observe the code path taken. Leaving the last field of the probe description blank will match the "entry" and "return" probes, and the instruction offset probes:
# dtrace -n 'pid$target:libc:strlen:' -p 809 dtrace: description 'pid$target:libc:strlen:' matched 24 probes CPU ID FUNCTION:NAME 1 63860 strlen:entry 1 76199 strlen:0 1 76200 strlen:4 1 76201 strlen:9 1 76202 strlen:b [...] 0 76216 strlen:37 0 76217 strlen:3c 0 76213 strlen:31 0 76214 strlen:34 [...]
DTrace can trace individual user-level instructions.
The first line of output says that DTrace "matched 24 probes": two for "entry" and "return", and 22 instruction offset probes. The output has been truncated to fit, but includes a jump from instruction offset 3c to 31. Examining that instruction in a debugger (here I used mdb):
libc.so.1`strlen+0x3c: jne -0xb <libc.so.1`strlen+0x31>
So, not surprisingly, that instruction was a jump (jump not equal to), to offset 0x31.
Out of Memory
Software is usually made up of thousands of functions, and those functions are usually made up of dozens of instructions. This results in many hundreds of thousands of instructions, if not millions, that can be probed using DTrace. To put this to the test, I'll list all instructions from all functions in libc:
# dtrace -ln 'pid$target:libc::' -p 809 | wc -l 157789
That's 157,788 probes, just for libc. Matching all instructions in this program, a bash shell, by using a wildcard for the second field as well:
# dtrace -ln 'pid$target:::' -p 809 | wc -l dtrace: invalid probe specifier pid$target:::: failed to create offset probes in 'setup': Not enough space 0
And there isn't enough memory for DTrace to complete. It's trying to create millions of probes, just for a shell process. Other applications (e.g., a web browser) are likely to have even more instructions.
Be careful with probe wildcards, you may try to instrument too much.
This is true regardless of which field is a wildcard. It's especially true of the last field, because that matches instruction offset probes as well, and so to make this point specifically:
Always use entry and return probes. Don't match instructions by accident.
Unless you really want to trace instructions for some reason. In my years of using DTrace, I've only needed to trace instructions about a dozen times (one of which has been included in the DTrace Book).
Instead of tracing all instruction probes (like above) to follow a code path, you can specify just a single instruction probe. Picking a single instruction probe is much safer - this causes less overhead on the target than tracing all instructions. For example, the dissassembly of strlen() is (via mdb):
> strlen::dis libc.so.1`strlen: movl 0x4(%esp),%eax libc.so.1`strlen+4: testl $0x3,%eax libc.so.1`strlen+9: jne +0x28 <libc.so.1`strlen+0x31> libc.so.1`strlen+0xb: nop libc.so.1`strlen+0xc: movl (%eax),%edx libc.so.1`strlen+0xe: movl $0x7f7f7f7f,%ecx libc.so.1`strlen+0x13: andl %edx,%ecx libc.so.1`strlen+0x15: addl $0x4,%eax libc.so.1`strlen+0x18: addl $0x7f7f7f7f,%ecx libc.so.1`strlen+0x1e: orl %edx,%ecx libc.so.1`strlen+0x20: andl $0x80808080,%ecx libc.so.1`strlen+0x26: cmpl $0x80808080,%ecx libc.so.1`strlen+0x2c: je -0x20 <libc.so.1`strlen+0xc> libc.so.1`strlen+0x2e: subl $0x4,%eax libc.so.1`strlen+0x31: cmpb $0x0,(%eax) libc.so.1`strlen+0x34: je +0xc <libc.so.1`strlen+0x40> libc.so.1`strlen+0x36: incl %eax libc.so.1`strlen+0x37: testl $0x3,%eax libc.so.1`strlen+0x3c: jne -0xb <libc.so.1`strlen+0x31> libc.so.1`strlen+0x3e: jmp -0x32 <libc.so.1`strlen+0xc> libc.so.1`strlen+0x40: subl 0x4(%esp),%eax libc.so.1`strlen+0x44: ret
Let's pick the 0x2e instruction to see if that was reached:
# dtrace -n 'pid$target:libc:strlen:2e' -p 14304 dtrace: description 'pid$target:libc:strlen:2e' matched 1 probe CPU ID FUNCTION:NAME 1 86169 strlen:2e 1 86169 strlen:2e 1 86169 strlen:2e ^C
In this case, it was - shedding light on the code path taken.
The pid provider instruction offset probe allows individual instructions to be traced in user-land code. The performance cost for DTrace observability is usually negligible; however, this is a case where the performance cost can be high - when tracing multiple instructions that are called frequently.
It's most important just to remember that this feature exists, so that you can avoid using it accidentally via probe name wildcards. You can revisit the docs if you hit a case where you really need to use it.