I’ve now been able to get perf to capture a user-space stack`, but I’m not sure how to convince it to capture values passed by reference as pointers, or to snapshot globals of interest.
Specifically, I’m trying to analyse the system-wide performance of PostgreSQL under various loads with and without a performance related patch. One of the key things I need to be able to do is tell which queries are associated with which block I/O requests in the kernel.
perf records the pid and the userspace stack, which sometimes contains the current_query, but since it’s a string it’s passed by reference so all I get is an opaque pointer. Not very useful. It doesn’t appear in all traces, either, so ideally I’d fish the value out of the global PostgreSQL stores it in and get perf to record that with each trace sample. Matching the pid to the query after the fact might be viable, but a given PostgreSQL backend (pid) doesn’t run just one query over its lifetime so lots of correlating timestamps between perf traces and PostgreSQL logs would be required.
This seems like the kind of thing you’d expect it to be able to do, since often a stack alone doesn’t tell you all that much about what’s going on and if it can already read the symbol table it should be able to look up globals and know which function arguments are pointers that need to be de-referenced and the first ‘n’ bytes copied.
I cannot for the life of me figure out how to do it or if this is possible, though. Am I just out of luck? Will I need to hack perf inject to merge this information from a separate timestamped log recorded by PostgreSQL?
Advertisement
Answer
It turns out that perf already has the required features for perf probe, but only for kernel-space at the moment.
perf probes can take arguments, which may be virtuals like $retval, registers like %ax, or c identifiers and simple expressions for local or global variables.
So, if perf did support user-space symbolic probes for arguments, you’d create a probe to capture the query_string argument to exec_simple_query is invoked with with something like:
perf probe -x /path/to/postgres exec_simple_query debug_query_string:string
The :string tells perf it’s a C string, so it should deref the pointer and copy the data.
There are multiple places queries can come in – the simple protocol, the v3 parse/bind/execute protocol, the SPI, etc. This is only one of them. You could capture the query from the parser in raw_parse instead, or grab the debug_query_string global value from probes on events of interest.
Unfortunately, none of this will work yet, because perf won’t do symbolic lookups on user-space binaries:
$ sudo perf probe -x /path/to/postgres exec_simple_query debug_query_string:string Debuginfo-analysis is not yet supported with -x/--exec option. Error: Failed to add events. (-38) $ perf --version; uname -r perf version 3.11.6 3.11.6-201.fc19.x86_64
So – if perf has support for symbolic lookups added you’ll be able to do exciting things like capture the query text in the executor by looking up a struct member:
perf probe -x `which postgres` standard_ExecutorStart 'queryDesc->sourceText:string'
… but again, perf doesn’t know how to do the required symbolic look-ups yet, and it can’t capture C strings from registers and $retval. So: wait for a new perf, unless you’re keen on enhancing the tooling yourself. Oh well.