My (attached) dtrace script tries to trace a tcp packet and report the
time spent in each processing function subtracting the time spent in
called functions. However when I run it I get -ve quantize
distribution. I do not see any -ve values being generated. Any ideas
what might be causing this. Is there is a better way to get the
information that I am trying to get.
Thanks,
Rao.
CPU ID FUNCTION:NAME
2 16938 putnext:entry putnext recursive call
0 2 :END
ip_tcp_input
value ------------- Distribution ------------- count
1024 | 0
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 163146
4096 | 58
8192 | 1
16384 | 0
socket_uc_queue_msg
value ------------- Distribution ------------- count
1024 | 0
2048 |@@@@@@ 18835
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 108811
8192 | 43
16384 | 0
mac_rx
value ------------- Distribution ------------- count
2048 | 0
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 142877
8192 | 6
16384 | 0
i_dls_link_rx
value ------------- Distribution ------------- count
2048 | 0
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 142850
8192 | 31
16384 | 1
32768 | 0
65536 | 0
131072 | 0
262144 | 1
524288 | 0
bge_receive
value ------------- Distribution ------------- count
512 | 0
1024 |@ 2402
2048 | 514
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 131322
8192 |@@@ 11561
16384 | 2
32768 | 0
tcp_rput_data
value ------------- Distribution ------------- count
-16384 | 0
-8192 | 1
-4096 | 10
-2048 | 707
-1024 |@ 4550
-512 | 206
-256 | 0
-128 | 0
-64 | 0
-32 | 0
-16 | 0
-8 | 0
-4 | 0
-2 | 0
-1 | 0
0 | 0
1 | 0
2 | 0
4 | 0
8 | 0
16 | 0
32 | 0
64 | 0
128 | 1
256 | 3
512 | 1
1024 | 14
2048 |@@ 6943
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 147377
8192 |@ 3387
16384 | 2
32768 | 1
65536 | 0
131072 | 0
262144 | 1
524288 | 0
bge_intr
value ------------- Distribution ------------- count
2048 | 0
4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 115768
8192 |@@@@@@@@ 30023
16384 | 3
32768 | 0
65536 | 0
131072 | 0
262144 | 7
524288 | 0
ip_input
value ------------- Distribution ------------- count
4096 | 0
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 126283
16384 |@@@@ 12540
32768 |@ 4041
65536 | 0
131072 | 0
262144 | 19
524288 | 0
#!/usr/sbin/dtrace -s
::bge_intr:entry
{
self->trace = 1;
self->prev = 0;
self->bge_intr = timestamp;
self->tcp_rput = 0;
self->so_queue_msg = 0;
self->putnext = 0;
}
::putnext:entry
/self->trace == 1/
{
self->putnext = timestamp;
}
::putnext:entry
/self->trace == 1 && self->putnext != 0/
{
/*
* recursive call
*/
printf ("putnext recursive call \n");
self->putnext_recr++;
}
::socket_uc_queue_msg:entry
/self->trace == 1/
{
self->so_queue_msg = timestamp;
}
::ip_input:entry
/self->trace == 1/
{
self->ip_input = timestamp;
}
::ip_tcp_input:entry
/self->trace == 1/
{
self->ip_tcp_input = timestamp;
}
::tcp_rput_data:entry
/self->trace == 1 && self->tcp_rput != 0/
{
/*
* recursive call
*/
printf ("tcp_rput_data recursive call \n");
self->tcp_rput_recr++;
}
::tcp_rput_data:entry
/self->trace == 1 && self->tcp_rput == 0/
{
self->tcp_rput = timestamp;
}
::bge_receive:entry
/self->trace == 1/
{
self->bge_recv = timestamp;
}
::bge_receive_ring:entry
{
self->bge_rring = timestamp;
}
::copymsgchain:entry
{
self->cmsg = timestamp;
}
::mac_rx:entry
/self->trace == 1/
{
self->mac_rx = timestamp;
}
::i_dls_link_rx:entry
{
self->dls_link_rx = timestamp;
}
::dld_str_rx_fastpath:entry
/self->trace == 1/
{
self->dls_rx_fast = timestamp;
}
::tcp_rput_data:return
/self->tcp_rput < 0/
{
printf ("self->tcp_rput < 0");
}
::tcp_rput_data:return
/self->prev < 0/
{
printf ("tcp_rput self->prev < 0");
}
::tcp_rput_data:return
/self->trace == 1 && self->tcp_rput_recr == 0/
{
@time[probefunc] = quantize(timestamp - self->tcp_rput - self->prev);
self->prev = timestamp - self->tcp_rput;
self->tcp_rput = 0;
}
::tcp_rput_data:return
/self->trace == 1 && self->tcp_rput_recr != 0/
{
self->tcp_rput_recr--;
}
::bge_intr:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->bge_intr - self->prev);
self->bge_intr = 0;
self->trace = 0;
self->prev = 0;
}
::bge_receive:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->bge_recv - self->prev);
self->prev = (timestamp - self->bge_recv);
self->bge_recv = 0;
}
::bge_receive_ring:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->prev - self->bge_rring);
self->prev = timestamp - self->bge_rring;
self->bge_rring = 0;
}
::copymsgchain:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->cmsg - self->prev);
self->prev = timestamp - self->cmsg;
self->cmsg = 0;
}
::mac_rx:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->mac_rx - self->prev);
self->prev = timestamp - self->mac_rx;
self->mac_rx = 0;
}
::i_dls_link_rx:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->dls_link_rx - self->prev);
self->prev = timestamp - self->dls_link_rx;
self->dls_link_rx = 0;
}
::dld_str_rx_fastpath:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->dls_rx_fast - self->prev);
self->prev = timestamp - self->dls_rx_fast;
self->dls_rx_fast = 0;
}
::ip_input:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->ip_input - self->prev - self->ip_tcp_input);
self->prev = timestamp - self->ip_input;
self->ip_input = 0;
}
::socket_uc_queue_msg:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->so_queue_msg);
self->prev = (timestamp - self->so_queue_msg);
self->so_queue_msg = 0;
}
::ip_tcp_input:return
/self->trace == 1/
{
@time[probefunc] = quantize(timestamp - self->ip_tcp_input);
self->ip_tcp_input = timestamp - self->ip_tcp_input;
}
::putnext:return
/self->trace == 1 && self->putnext_recr == 0 /
{
@time[probefunc] = quantize(timestamp - self->putnext);
self->prev = timestamp - self->putnext;
}
::putnext:return
/self->trace == 1 && self->putnext_recr != 0 /
{
self->putnext_recr--;
}
END
{
trunc(@time,10);
}
_______________________________________________
dtrace-discuss mailing list
[email protected]
