20.5. Task Queue Observability20.5.1. Kstat CountersEvery taskq created in the system keeps a set of associated kstat counters. Try running the following command on your system. sol9$ kstat -c taskq module: unix instance: 0 name: ata_nexus_enum_tq class: taskq crtime 53.877907833 executed 0 maxtasks 0 nactive 1 nalloc 0 priority 60 snaptime 258059.249256749 tasks 0 threads 1 totaltime 0 module: unix instance: 0 name: callout_taskq class: taskq crtime 0 executed 13956358 maxtasks 4 nactive 4 nalloc 0 priority 99 snaptime 258059.24981709 tasks 13956358 threads 2 totaltime 120247890619 ... The kstat information above includes
You can use the power of the kstat command to observe how some counter increases over time. sol9$ kstat -p unix:0:callout_taskq:tasks 1 5 unix:0:callout_taskq:tasks 13994642 unix:0:callout_taskq:tasks 13994711 unix:0:callout_taskq:tasks 13994784 unix:0:callout_taskq:tasks 13994855 unix:0:callout_taskq:tasks 13994926 ... 20.5.2. DTrace SDT ProbesThe taskq implementation also provides several useful SDT probes. The probes described below have two arguments: the taskq pointer and the pointer to the taskq_ent_t structure, which can extract the function and the argument from the D script.
Developers 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 prints the functions that were scheduled through task queues 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 a desktop produced the following output. 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 |