I've been learning about different ways to do dynamic tracing. While
following different threads on the mailing list, I've come to the conclusion
that Linus and Al and probably a bunch of others hate to see printks and
tracepoints and other kinds of debug stuff sprinkled all around in kernel
code, and Orangefs is one module that tons of "gossip_debug" (wrapped printk)
statements. They've always been there, I use them a lot, so I've
been looking at how to "do that kind of stuff" dynamically.
There's kprobe kernel modules, where you write a kernel module that
patches arbitrary stuff into existing code, on the fly even. Powerful
and cool, but way more awkward than just flipping gossip on and off in
different parts of our code.
There's the kind of kprobes that you echo into
/sys/kernel/debug/tracing/events/kprobes, but I can only see
how to use them to printout structure addresses and stuff, I don't
see how to use them to dereference the contents of structures... they're
pretty powerful and lightweight and easy, though, and they can be inserted
at arbitrary places, not just at function entry and exit points.
There's the kind of kprobes you can make with eBPF, which I studied
from the perspective of bcc and all that clang/python/LLVM stuff...
way powerful, there's probably plenty I fail to appreciate about it,
but again, pretty awkward compared to turning on gossip statements.
I don't see how to make these kprobes anywhere other than at function
entry and exit, perhaps it is easy... you can use them to dereference
pointer values too.
What really seems AWESOME is the kind of probes you can insert with
"perf probe".
You can use "perf probe -L" to find probeable lines in arbitrary kernel
functions.
You can use "perf probe -V" to find probeable symbols at particular
line numbers:
-------------------------------------------------------------------------------
perf probe -m orangefs -V orangefs_symlink:12
Available variables at orangefs_symlink:12
@<orangefs_symlink+44>
char* __func__
char* symname
int ret
struct dentry* dentry
struct inode* dir
-------------------------------------------------------------------------------
You can use "perf probe -a" to add tracepoints for any of the symbols you
find, including dereferencing ones that are structure pointers:
-------------------------------------------------------------------------------
perf probe -m orangefs -a 'orangefs_symlink:12 dentry->d_name.name:string'
Added new event:
probe:orangefs_symlink (on orangefs_symlink:12 in orangefs with
name=dentry->d_name.name:string)
You can now use it in all perf tools, such as:
perf record -e probe:orangefs_symlink -aR sleep 1
perf record -e probe:orangefs_symlink -aR ln -s /pvfsmnt/foo /pvfsmnt/foo2_sym20
perf script
ln 31454 [000] 522096.392556: probe:orangefs_symlink:
(ffffffffc072afc8) name="foo2_sym20"
-------------------------------------------------------------------------------
If you get handy with these few commands, it seems it would be easy to
dynamically obtain the same information I'm used to getting with gossip,
and cheaper too: tracepoints are lightweight... a bunch of printks can
change timing problems so that "oh crap, I turned on debug and now the
problem doesn't happen anymore"...
Unfortunately, there's either something broken about "perf probe", or
(more likely, maybe <g>) something I don't understand about it. I get
this kind of stuff a lot, I've used 4.10 and 4.11 rc2 with the same
kind of results:
-------------------------------------------------------------------------------
perf probe -m orangefs -V service_operation:122
Available variables at service_operation:122
@<service_operation+606>
char* __func__
int ret
long int timeout
struct orangefs_kernel_op_s* op
wait_queue_t wait_entry
tools/perf/perf probe -m orangefs -a 'service_operation:122 op->tag'
Failed to write event: Invalid argument
Error: Failed to add events.
[dmesg]
Could not insert probe at orangefs:service_operation+1212: -84
Probing address(0xffffffffc072efac) is not an instruction boundary.
-------------------------------------------------------------------------------
I think it is a coincidence that "122" and "1212" look similar...
-------------------------------------------------------------------------------
perf probe -m orangefs -a 'service_operation+606 op->tag'
Failed to write event: Invalid argument
Error: Failed to add events.
Could not insert probe at orangefs:service_operation+1212: -84
Probing address(0xffffffffc0737fec) is not an instruction boundary.
-------------------------------------------------------------------------------
Anyhow, I copied mhiramat@xxxxxxxxxx, who does a lot of work on the
perf code, on this message, and if anyone who is going to lsf/mm or
Vault reads this far, maybe we can talk about it in the hall...
-Mike
