hmm...
thanks - in order to do as you suggest, I guess
the "flowindent" has to be removed ?
( dtrace script at end of email... )
thanks
wr
-----Original Message-----
From: Brian Utterback [mailto:brian.utterback at sun.com]
Sent: Wednesday, September 24, 2008 9:57 AM
To: William Reich
Cc: dtrace-discuss at opensolaris.org
Subject: Re: [dtrace-discuss] showing concurrency with Dtrace
Dtrace does buffer the output. The trick is to use print the timestamp
variable on each output line and then sort numerically by the timestamp.
This will put the lines back into their original chronological order.
William Reich wrote:> HI all...
>
> We have a Streams application that has several streams in our
> configuration.
>
> We are trying to show that the multiple streams are actually executing
> concurrently.
>
> Will Dtrace show us the concurrency ?
> ( or is there somekind of buffering of output occurring that will hide
> any concurrency ? )
>
> wr
>
++++++++++++++++++++++++++++++++++++++++
#!/usr/sbin/dtrace -s
#pragma D option flowindent
#pragma D option dynvarsize=4m
BEGIN
{
self->times = 0;
self->depth = 0;
}
:mom:momURSrv:entry
{
self->times = timestamp;
}
:mom:momUWPut:entry
{
self->times = timestamp;
}
:mom:momLWSrv:entry
{
self->times = timestamp;
}
:mom:momLRPut:entry
{
self->times = timestamp;
}
:ulom:lom_uwput:entry
{
self->times = timestamp;
}
:ulom:lom_rsrv:entry
{
self->times = timestamp;
}
:ulom:lom_lrsrv:entry
{
self->times = timestamp;
}
:ulom:lom_lrput:entry
{
self->times = timestamp;
}
:ulom:lom_wsrv:entry
{
self->times = timestamp;
}
:c7l3rt:c7l3rt_wput:entry
{
self->times = timestamp;
}
:c7l3rt:c7l3rt_wsrv:entry
{
self->times = timestamp;
}
:c7l3rt:c7l3rt_rsrv:entry
{
self->times = timestamp;
}
:c7l3rt:c7l3rt_rput:entry
{
self->times = timestamp;
}
:pcimb3:pcimb3_wsrv:entry
{
self->times = timestamp;
}
:pcimb3:pcimb3_rsrv:entry
{
self->times = timestamp;
}
:pcimb3:pcimb3_wput:entry
{
self->times = timestamp;
}
:mom:momURSrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:mom:momUWPut:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:mom:momLWSrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:mom:momLRPut:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:ulom:lom_uwput:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:ulom:lom_rsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:ulom:lom_lrsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:ulom:lom_lrput:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:ulom:lom_wsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:c7l3rt:c7l3rt_wput:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:c7l3rt:c7l3rt_wsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:c7l3rt:c7l3rt_rsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:c7l3rt:c7l3rt_rput:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:pcimb3:pcimb3_wsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:pcimb3:pcimb3_rsrv:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
:pcimb3:pcimb3_wput:return
/self->times/
{
@[probemod, probefunc] = avg(timestamp - self->times);
self->times = 0;
}
/* solaris kernel streams related functions, entry points
* as well as the ulticom module(s)
*/
fbt:mom:momUWPut:entry,
fbt:mom:momURSrv:entry,
fbt:mom:momLWSrv:entry,
fbt:mom:momLRPut:entry,
fbt:ulom:lom_uwput:entry,
fbt:ulom:lom_rsrv:entry,
fbt:ulom:lom_wsrv:entry,
fbt:ulom:lom_lrsrv:entry,
fbt:ulom:lom_lrput:entry,
fbt:c7l3rt:c7l3rt_wput:entry,
fbt:c7l3rt:c7l3rt_rsrv:entry,
fbt:c7l3rt:c7l3rt_rput:entry,
fbt:c7l3rt:c7l3rt_wsrv:entry,
fbt:pcimb3:pcimb3_wsrv:entry,
fbt:pcimb3:pcimb3_rsrv:entry,
fbt:pcimb3:pcimb3_wput:entry,
fbt:genunix:getq:entry,
fbt:unix:putnext:entry,
fbt:genunix:putq:entry
/self->times/
{
trace(timestamp);
trace(self->depth);
self->start[self->depth] = timestamp;
self->depth++;
}
/* solaris kernel streams related functions, return points
* as well as the ulticom module(s)
*/
fbt:mom:momUWPut:return,
fbt:mom:momURSrv:return,
fbt:mom:momLWSrv:return,
fbt:mom:momLRPut:return,
fbt:ulom:lom_uwput:return,
fbt:ulom:lom_rsrv:return,
fbt:ulom:lom_wsrv:return,
fbt:ulom:lom_lrsrv:return,
fbt:ulom:lom_lrput:return,
fbt:c7l3rt:c7l3rt_wput:return,
fbt:c7l3rt:c7l3rt_rsrv:return,
fbt:c7l3rt:c7l3rt_rput:return,
fbt:c7l3rt:c7l3rt_wsrv:return,
fbt:pcimb3:pcimb3_wsrv:return,
fbt:pcimb3:pcimb3_rsrv:return,
fbt:pcimb3:pcimb3_wput:return,
fbt:genunix:getq:return,
fbt:unix:putnext:return,
fbt:genunix:putq:return
/self->times && self->start[self->depth - 1]/
{
self->depth--;
trace(timestamp);
trace(self->depth);
trace((timestamp - self->start[self->depth]));
self->start[self->depth] = 0;
}
tick-1sec
{
exit(0);
}