I am also seeing same problem. Test run as follows.
syscall::umask:entry
{
@execnameCntonly[execname, ustack()] = count();
}
bash-3.00# chmod 777 /tmp/abctsidx
bash-3.00# chmod 777 /tmp/abctsidx
bash-3.00# chmod 777 /tmp/abctsidx
bash-3.00# chmod 777 /tmp/abctsidx
bash-3.00# chmod 777 /tmp/abctsidx
chmod
0xfeefb7d5
0x8051026
2
chmod
0xfeefb7d5
0x8051026
2
chmod
0xfeefb7d5
0x8051026
2
chmod
0xfeefb7d5
0x8051026
2
chmod
0xfeefb7d5
0x8051026
2
________________________________
From: Kelly Caudill <kelly.caud...@oracle.com>
To: dtrace-discuss@opensolaris.org
Sent: Thursday, November 8, 2012 6:55 AM
Subject: [dtrace-discuss] aggregation on ustack() not aggregating
I would like to "profile" when threads in certain processes go to sleep.
The following seems to work, but...
sched:::off-cpu
/execname == "MyProg" && curlwpsinfo->pr_state == SSLEEP/
{
self->sleepStart = timestamp;
}
sched:::on-cpu
/self->sleepStart/
{
this->slept = timestamp - self->sleepStart;
/* I want specifics about LWP#s < 20 and combine all others */
this->thrd = tid < 20 ? tid : 0;
@sleepCnt[this->thrd,ustack()] = count();
@sleepAvg[this->thrd,ustack()] = avg(this->slept);
@sleepTot[this->thrd,ustack()] = sum(this->slept);
@SleepCnt[pid] = count();
@TotSlp[pid] = sum(this->slept);
self->sleepStart = 0;
}
dtrace:::END
{
trunc(@sleepTot, 10);
trunc(@sleepCnt, 20);
trunc(@sleepAvg, 10);
normalize(@sleepTot,1000000);
normalize(@sleepAvg,1000000);
printa("lwp %d slept (tot=%@dms) %@d times (avg=%@dms) like this:%-6k\n",
@sleepTot, @sleepCnt, @sleepAvg);
}
but I do not understand why it does not combine some entries like:
lwp 5 slept (tot=0ms) 0 times (avg=30000ms) like this:
libc.so.1`__lwp_park+0x10
libc.so.1`cond_wait_queue+0x4c
libc.so.1`cond_wait_common+0x2d4
libc.so.1`_cond_timedwait+0x34
libc.so.1`cond_timedwait+0x14
libc.so.1`pthread_cond_timedwait+0xc
libnspr4.so`pt_TimedWait+0xe0
libnspr4.so`PR_WaitCondVar+0x190
libnspr4.so`PR_Wait+0x1c
libmqcrt.so.1`0xffffffff57657c48
libnspr4.so`_pt_root+0xa8
libc.so.1`_lwp_start
lwp 5 slept (tot=0ms) 0 times (avg=30000ms) like this:
libc.so.1`__lwp_park+0x10
libc.so.1`cond_wait_queue+0x4c
libc.so.1`cond_wait_common+0x2d4
libc.so.1`_cond_timedwait+0x34
libc.so.1`cond_timedwait+0x14
libc.so.1`pthread_cond_timedwait+0xc
libnspr4.so`pt_TimedWait+0xe0
libnspr4.so`PR_WaitCondVar+0x190
libnspr4.so`PR_Wait+0x1c
libmqcrt.so.1`0xffffffff57657c48
libnspr4.so`_pt_root+0xa8
libc.so.1`_lwp_start
lwp 5 slept (tot=0ms) 0 times (avg=30000ms) like this:
libc.so.1`__lwp_park+0x10
libc.so.1`cond_wait_queue+0x4c
libc.so.1`cond_wait_common+0x2d4
libc.so.1`_cond_timedwait+0x34
libc.so.1`cond_timedwait+0x14
libc.so.1`pthread_cond_timedwait+0xc
libnspr4.so`pt_TimedWait+0xe0
libnspr4.so`PR_WaitCondVar+0x190
libnspr4.so`PR_Wait+0x1c
libmqcrt.so.1`0xffffffff57657c48
libnspr4.so`_pt_root+0xa8
libc.so.1`_lwp_start
Those are just one example of thread stacks that seem identical but were not
combined into a single aggregation bucket.
Some of the numbers are 0 due to the trun(xx,N) before the print - because I
only want to see the (hopefully) few worst offenders.
But since it does not combine them properly, the list is overwhelmed with like
above which, unfortunately, are a case I don't actually care about. If it
combined those, then I the other few printed should be what I do care about.
Am I doing something wrong?
Excluding the stacks like above, by setting a flag when it enters that
function, is problematic because it requires using the pid provider and then I
can only watch one process at a time.
Kelly
_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org
