Re: warning dump

[ersatz splatt <ersatzsplatt at gmail dot com>]

Thanks much Josh!

Adding .call to the function reference gets rid of all the warnings.
... and makes the trace much more readable.  It also boosts the IOPS
to about 23k.  Turning the prints back on will bump it back down.  It
is nice to have some clarity about the operation.


Regards,
David



On Fri, Jun 17, 2011 at 1:03 PM, Josh Stone <jistone@redhat.com> wrote:
> On 06/17/2011 12:22 PM, ersatz splatt wrote:
>> When I run a script to trace activity of a loaded driver, I get a
>> warning dump (below). ?This is not really a big problem for me ...
>> since it does drive a trace output. ?I would like to understand the
>> source of the problem more clearly though -- to better trust my
>> results.
>
> The two return codes shown are -22 (-EINVAL) and -84 (-EILSEQ). ?These
> are codes from kprobes internals, not systemtap itself. ?There's not
> much to go on to find out why, but you can peruse through:
>
> ?kernel/kprobes.c
> ?arch/x86/kernel/kprobes.c
>
> EINVAL is all over the place, but EILSEQ only shows up in the arch code,
> either from the test !can_probe() in arch_prepare_kprobe() or from
> !can_optimize() in arch_prepare_optimized_kprobe(). ?The return value
> from _optimized is not checked or reported (eek!), so it must be an
> error of can_probe(). ?The comment of that function is:
>
> ?/* Check if paddr is at an instruction boundary */
>
> Apparently it thinks some of your probes are not on instruction
> boundaries. ?This could be a kprobes bug or a systemtap placement bug,
> but it's hard to say without looking at your actual module versus the
> stap's probe addresses.
>
>> I also see a pretty heavy load on the system when running this -- even
>> when I comment the prints out. ?Without systemtap, I'm getting about
>> 70k IOPS per fio. ?With the systemtap script running (see below the
>> warning dump -- though the prints are not commented out) I get about
>> 17K IOPS. ?I know I can make a scripts that is not as heavy (by being
>> more selective about which functions I'm probing) and I (think I) get
>> the call trace I'm looking for anyhow. ?Some other work I'm doing I
>> still see a very heavy hit on I/O performance with only a few probe
>> points ... but that is getting too deep into another discussion.
>
> Even without prints, you're taking an INT3 debug trap for every probe
> that's encountered. ?The kprobe optimizer tries to turn these into
> function calls instead, but it can't always do that. ?So whatever you
> can do to reduce the number of probes placed will probably help.
>
> For instance:
>
>> probe module("pm8001").function("*") {
>
>> probe module("pm8001").function("*").return {
>
> Your script looks like it wants balanced call/return. ?You may not be
> aware though, the first one actually covers both .call and .inline
> function variants, and there's no .return to match .inline. ?Your script
> will correctly balanced if you use .call on the first probe, and then
> you'll also save overhead where there were .inline probes before.
>
>
> Josh
>