This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
Re: measuring accept queueing time (revisited)
Josh Stone <jistone@redhat.com> wrote:
> On 11/30/2012 02:35 PM, Eric Wong wrote:
> > /* XXX: This doesn't seem to work, so I'm probing skb_recv_diagram instead */
> > probe kernel.function("unix_accept").return {
> > if ($return != 0)
> > next
> > sk = $newsock->sk
> > /* state: 3 == SS_CONNECTED, but this shows 1 (SS_UNCONNECTED) ... */
> > /* printf("accept %d %lx %lx\n", $newsock->state, $newsock, sk); */
>
> This is probably an instance of one common confusion -- in .return
> probes, all instances of $var, $var->member, etc. are captured when the
> function is *entered* (except for $return, of course). The context in
> which the return trampoline actually runs is just not amenable to
> decoding DWARF from the function we just left.
>
> So it makes twisted sense to see SS_UNCONNECTED from the entry of
> unix_accept, but you want to see the SS_CONNECTED when it returns.
>
> One way to cheat this is to go ahead and grab the implicit entry value
> for $newsock, and then use a dynamic @cast to get the member you really
> want at return time. Something like:
> @cast($newsock, "struct socket")->state
>
> You probably need the same for $newsock->sk too.
Ah, thank you! I was very confused by sk==0 and state==SS_UNCONNECTED
but your explanation makes sense.
> We had an old bug arguing about whether delaying member access should be
> standard, which I can't find now. Suffice to say we never agreed to
> change this behavior, so here we are. PR14437 would give a mechanism to
> be explicit about it though, like @entry($newsock)->state.
> http://sourceware.org/bugzilla/show_bug.cgi?id=14437
That's the one surprising/confusing thing I've found about the language
so far. Otherwise, I'm very happy at how easy and powerful this is!
I think I'll just declare start with '%' for wrapping and not worry
about future/past callers of unix_create1(). I may not even need to
probe unix_create() at all with wrapping...
Here's my updated unix_accept.stp:
-------------------------------- 8< ------------------------------
/* wrap in case there are more unix_create1() callers in other versions */
global start%
/*
* 3.6.8 only has two unix_create1() callers:
* - unix_stream_connect() - we care about this
* - unix_create() - we don't care about this
*/
probe kernel.function("unix_create1").return {
start[$return] = cpu_clock_ms(0)
}
/*
* we only care about unix_create1() called from unix_stream_connect(),
* so avoid wasting space here.
*/
probe kernel.function("unix_create").return {
delete start[$return]
}
probe kernel.function("unix_accept").return {
if ($return != 0)
next
sk = @cast($newsock, "struct socket")->sk
started = start[sk]
if (started) {
delete start[sk]
diff = cpu_clock_ms(0) - started
printf("%s[%d] %ld\n", execname(), pid(), diff)
}
}
-------------------------------- 8< ------------------------------