it''s written that plockstat,easures user level locking, what kind of locks does it exactly trace? Does plockstat measure user level pthreads? Thanks. This message posted from opensolaris.org
On Sat 17 Mar 2007 at 12:56PM, Neelam wrote:> it''s written that plockstat,easures user level locking, what > kind of locks does it exactly trace? Does plockstat measure user > level pthreads?Yes, it does-- on Solaris pthreads and "classic Solaris threads" are really the same thing underneath. plockstat uses DTrace to instrument these, and to record events of interest. Here''s an example: # plockstat -p 100147 <wait a few secs, then Ctrl-C> ^C R/W reader block Count nsec Lock Caller ------------------------------------------------------------------------------- 563 6630 nscd`getent_ctxDB_rwlock nscd`_nscd_is_getent_ctx+0x35 13 9570 nscd`nscd_nsw_state_base_lock nscd`_get_nsw_state_int+0x10a 26 4160 nscd`addrDB_rwlock nscd`_nscd_is_int_addr+0x36 11 2674 nscd`nscd_smf_service_state_lock nscd`_nscd_get_smf_state+0xb1 8 2594 0x80c8a84 nscd`_nscd_is_int_addr+0x60 8 2469 0x80bcb04 nscd`_nscd_is_int_addr+0x60 1 14213 nscd`nscd_getent_ctx_base_lock nscd`_nscd_get_getent_ctx+0x3c 5 2290 0x80bcce4 nscd`_nscd_is_int_addr+0x60 3 3569 libnsl.so.1`rpcbaddr_cache_lock libnsl.so.1`_getclnthandle_timed+0x2f 2 2404 0x80bee34 nscd`_nscd_is_int_addr+0x60 2 2398 0x80bea74 nscd`_nscd_is_int_addr+0x60 1 2485 0x809bf5c nscd`_nscd_is_int_addr+0x60 R/W writer block Count nsec Lock Caller ------------------------------------------------------------------------------- 5 6785 nscd`nscd_smf_service_state_lock nscd`query_smf_state+0x68 3 6396 nscd`nscd_smf_service_state_lock nscd`query_smf_state+0x68 1 3074 libnsl.so.1`rpcbaddr_cache_lock libnsl.so.1`add_cache+0x115 1 3073 nscd`getent_ctxDB_rwlock nscd`_nscd_add_getent_ctx+0x71 You can also use plockstat -V, which prints out the D program used, to see how it works. This could help you to develop your own instrumentation if you wished. For example: # plockstat -V -p 100147 plockstat: vvvv D program vvvv plockstat$target:::rw-block { self->rwblock[arg0] = timestamp; } plockstat$target:::mutex-block { self->mtxblock[arg0] = timestamp; } plockstat$target:::mutex-spin { self->mtxspin[arg0] = timestamp; } plockstat$target:::rw-blocked /self->rwblock[arg0] && arg1 == 1 && arg2 != 0/ { @rw_w_block[arg0, ustack(5)] sum(timestamp - self->rwblock[arg0]); ... -dp -- Daniel Price - Solaris Kernel Engineering - dp at eng.sun.com - blogs.sun.com/dp
User level locks are locks created used by application code. Mutex locks and reader/writer locks. See mutex_init() and rwlock_init() for more about these locks. Also see http://docs.sun.com/app/docs/doc/816-5137/6mba5vpjd?a=view /jim Neelam wrote:> it''s written that plockstat,easures user level locking, what kind of locks does it exactly trace? > Does plockstat measure user level pthreads? > > > Thanks. > > > This message posted from opensolaris.org > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org >
I''ld like to collect data with dtrace sufficient to generate two
types of time-lines of thread switch activity:
time:
+-------------------------------------------------------------
cpu:|0 tid->tid
|1 tid->tid
|2 tid->tid
|.
|.
|.
|N tid->tid tid->tid
(note \ __ and __\ tids should match! )
and:
time:
+-------------------------------------------------------------
tid:|0 +--------cpu0-------+ +------cpu1-------
|1
|2 +-----cpu1------+
|.
|.
|. +------cpu1-----------+
|N +-----------cpu0-------------------
does anyone have suggestions for what probes to use (not how to get
the output formatted as graphs, that will probably be a post-processor)
I tried tnf_thread_switch, but I don''t get any output, even after I
use mdb -wk to set tnf_thread_active to 1
thanks,
Pete Lawrence.
cloudbase# mdb -wk> tnf_tracing_active/W 1
tnf_tracing_active: 0 =
0x1> ::quit
cloudbase# dtrace -n
''fbt:genunix:tnf_thread_switch:entry{trace(tid)}''
dtrace: description ''fbt:genunix:tnf_thread_switch:entry''
matched 1 probe
...but no output...
Hi Peter, How about sysinfo:::pswitch? Chip Peter Lawrence wrote:> I''ld like to collect data with dtrace sufficient to generate two > types of time-lines of thread switch activity: > > ... >
Sounds like you want on-cpu, off-cpu. On 3/22/07, Peter Lawrence <Peter.Lawrence at sun.com> wrote:> > I''ld like to collect data with dtrace sufficient to generate two > types of time-lines of thread switch activity: > > > > time: > +------------------------------------------------------------- > cpu:|0 tid->tid > |1 tid->tid > |2 tid->tid > |. > |. > |. > |N tid->tid tid->tid > > (note \ __ and __\ tids should match! ) > > > and: > > time: > +------------------------------------------------------------- > tid:|0 +--------cpu0-------+ +------cpu1------- > |1 > |2 +-----cpu1------+ > |. > |. > |. +------cpu1-----------+ > |N +-----------cpu0------------------- > > > > does anyone have suggestions for what probes to use (not how to get > the output formatted as graphs, that will probably be a post-processor) > > > I tried tnf_thread_switch, but I don''t get any output, even after I > use mdb -wk to set tnf_thread_active to 1 > > > thanks, > Pete Lawrence. > > > cloudbase# mdb -wk > > tnf_tracing_active/W 1 > tnf_tracing_active: 0 = 0x1 > > ::quit > > cloudbase# dtrace -n ''fbt:genunix:tnf_thread_switch:entry{trace(tid)}'' > dtrace: description ''fbt:genunix:tnf_thread_switch:entry'' matched 1 probe > > ...but no output... > > > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org >-- Just me, Wire ...
All,
so far the best reference doc I''ve seen for dtrace is
Bryan''s
original "DTrace Quick Reference" at <dtrace.eng/usage.html>
(sorry
to those outside of Sun, this is an internal web page).
None of Sun''s official Docs, nor the stuff at opensolaris.org seem
to be as usable, and the key word here is "usable". But it is a bit
out of date, not all of the currently supported Providers are in there.
If no-one else wants to do it, I''ll probably try updating it myself.
Any other takers?
Pete Lawrence.
On Thu, Mar 22, 2007 at 10:32:24AM -0700, Peter Lawrence wrote:> All, > so far the best reference doc I''ve seen for dtrace is Bryan''s > original "DTrace Quick Reference" at <dtrace.eng/usage.html> (sorry > to those outside of Sun, this is an internal web page).Boy, that''s turning the way-back dial -- that page was last updated by Mike in December 2002! I have attached this page for those not at Sun -- if nothing else for its time capsuled gems like "Future prototypes will expose a library programming API, but this is not yet available." The API is certainly there, but I think we''re still waiting to expose it. ;) Do note that some of this page is now explicitly wrong, e.g.: - END. Probe triggered after tracing has stopped due to an explicit termination of tracing from the DTrace consumer. When using dtrace(1M), the END probe is triggered after receipt of a SIGINT or SIGTERM (e.g., ^C). The END probe is not triggered after an exit action. We ultimately realized that this last sentence represented completely busted semantics; the END probe _does_ fire on an explicit exit(), and has since the go-go days of d10_36, released internally on June 19, 2003.> None of Sun''s official Docs, nor the stuff at opensolaris.org seem > to be as usable, and the key word here is "usable". But it is a bit > out of date, not all of the currently supported Providers are in there. > > If no-one else wants to do it, I''ll probably try updating it myself.Please, have at it! If you send the update to Mike, Adam, Brendan or me, we''ll put it up on opensolaris.org... - Bryan -------------------------------------------------------------------------- Bryan Cantrill, Solaris Kernel Development. http://blogs.sun.com/bmc -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20070322/a02af618/attachment.html>
All,
does anyone have a cute trick for finding out what''s being done
by this kernel taskq thread, like maybe doing fbt for a somehow limited
number of calls after resuming...?... (I''m pretty sure that if I saw
the first 10 or so calls I could tell what its doing...)
I''ld like to set up a predicate to an fbt probe and have the predicate
set by the on-cpu probe and then decremented by the fbt probe, and
I''ld also like the pid-tid to be part of the predicate, but...
why do all pure-kernel threads seem to have tid = 0, is tid maintained
only by the sun/posix user lib code and not an essential attribute of
all threads ? or are kernel tids 0 because of a glitch, or what ?
thanks,
Pete Lawrence.
6 475 resume:on-cpu .cpu-6, pid0_thd0, pil-0.
unix`_resume_from_idle+0x1cc
genunix`cv_wait+0x38
genunix`taskq_thread+0xdc
unix`thread_start+0x4
6 465 resume:off-cpu .cpu-6, pid0_thd0, pil-11.
unix`resume+0x4
genunix`cv_wait+0x38
genunix`taskq_thread+0xdc
unix`thread_start+0x4
#!/usr/sbin/dtrace -Cs
dtrace:::BEGIN
{
}
sched:::on-cpu
{
printf (" .cpu-%d, pid%d_thd%d, pil-%d.", cpu, pid, tid,
ipl);
stack (999);
ustack (999, 1000);
}
sched:::off-cpu
{
printf (" .cpu-%d, pid%d_thd%d, pil-%d.", cpu, pid, tid,
ipl);
stack (999);
ustack (999, 1000);
printf ("--------------------------------\n");
printf ("\n");
printf ("\n");
}
Brendan Gregg - Sun Microsystems
2007-Mar-22 23:16 UTC
[dtrace-discuss] dtracing thread swtiches
G''Day Peter, On Thu, Mar 22, 2007 at 10:32:24AM -0700, Peter Lawrence wrote:> All, > so far the best reference doc I''ve seen for dtrace is Bryan''s > original "DTrace Quick Reference" at <dtrace.eng/usage.html> (sorry > to those outside of Sun, this is an internal web page). > > None of Sun''s official Docs, nor the stuff at opensolaris.org seem > to be as usable, and the key word here is "usable". But it is a bit > out of date, not all of the currently supported Providers are in there.I learnt DTrace using the official Docs just fine (and with help on dtrace-discuss). The DTrace Guide is one of the best docs you''ll find on docs.sun.com, and contains these tables anyway spread out in different chapters. I do agree that having them on one page is quite a useful quick reference, and I''d be happy to put an updated copy on opensolaris.org. And yes, bringing the material such as provider docs up to date is important too. I think a usability problem with DTrace documentation is the target audience - I know many customers don''t find the DTrace Guide "just fine", as they don''t have time to pick through and find the content that is relavent to their role. This seems especially the case for application developers who don''t have root access, and are interested in DTracing a language such as Java. I''m going to try to help by writing some targeted documentation as I get spare cycles. Brendan -- Brendan [CA, USA]
> All, > does anyone have a cute trick for finding out what''s being done > by this kernel taskq thread, like maybe doing fbt for a somehow limited > number of calls after resuming...?... (I''m pretty sure that if I saw > the first 10 or so calls I could tell what its doing...)The taskq implementation provides several useful SDT probes: All the probes described below have two arguments: the taskq pointer and the pointer to the taskq_ent_t structure. It can be used to extract the function and the argument from the D script. - taskq-enqueue probe fires whenever a task is enqueued on the taskq. - taskq-exec-start probe fires just before the task is about to be executed. - taskq-exec-end probe fires right after the task is executed. You can use these probes to collect precise timing information about individual task queues and individual tasks being executed through them. For example, the following script will print what functions were scheduled via task queues for every 10 seconds: #!/usr/sbin/dtrace -qs sdt:genunix::taskq-enqueue { this->tq = (taskq_t *)arg0; this->tqe = (taskq_ent_t *) arg1; @[this->tq->tq_name, this->tq->tq_instance, this->tqe->tqent_func] = count(); } tick-10s { printa ("%s(%d): %a called %@d times\n", @); trunc(@); } Running this on my desktop produced the following output1: callout_taskq(1): genunix`callout_execute called 51 times callout_taskq(0): genunix`callout_execute called 701 times kmem_taskq(0): genunix`kmem_update_timeout called 1 times kmem_taskq(0): genunix`kmem_hash_rescale called 4 times callout_taskq(1): genunix`callout_execute called 40 times USB_hid_81_pipehndl_tq_1(14): usba`hcdi_cb_thread called 256 times callout_taskq(0): genunix`callout_execute called 702 times kmem_taskq(0): genunix`kmem_update_timeout called 1 times kmem_taskq(0): genunix`kmem_hash_rescale called 4 times callout_taskq(1): genunix`callout_execute called 28 times USB_hid_81_pipehndl_tq_1(14): usba`hcdi_cb_thread called 228 times callout_taskq(0): genunix`callout_execute called 706 times callout_taskq(1): genunix`callout_execute called 24 times USB_hid_81_pipehndl_tq_1(14): usba`hcdi_cb_thread called 141 times callout_taskq(0): genunix`callout_execute called 708 times - Alex Kolbasov __ http://blogs.sun.com/akolb