Page MenuHomeFreeBSD

lockstat(1): use lock names instead of addresses
ClosedPublic

Authored by markj on Sep 13 2015, 10:05 PM.

Details

Summary

lockstat(1) currently uses lock addresses as identifiers and uses ksyms
to look up the associated symbol. As many locks are embedded into
dynamically-allocated structures, this doesn't work too well. However,
in FreeBSD we can do better since the lock object contains a name for
the lock. This change converts lockstat(1) to use lock names instead of
addresses as identifiers.

This breaks the -c option, which tells lockstat to attempt to coalesce
info for arrays of locks. Since FreeBSD has relatively few examples of
such arrays (sched locks and page locks are the only examples come to
mind), just disable it for now. If it turns out to be more useful than I
thought, it could be fixed by tracing both lock addresses and names.

Test Plan

Without the change:

$ sudo lockstat -e 0,1 sleep 5

Adaptive mutex spin: 42 events in 5.013 seconds (8 events/sec)

Count indv cuml rcnt nsec Lock Caller

12  29%  29% 0.00    14237 0xfffffe0001430990     usbd_transfer_pending+0xa2
 5  12%  40% 0.00      518 0xfffff8000de18520     doselwakeup+0x132
 4  10%  50% 0.00    14339 0xfffff8000d431090     usbd_do_request_flags+0x5e3
 3   7%  57% 0.00     1595 0xfffff8000d431090     usb_callback_proc+0xd9
 2   5%  62% 0.00    23216 Giant                  usbd_enum_lock+0x10f
 2   5%  67% 0.00      243 0xfffff800246f14c0     sopoll_generic+0x84
 1   2%  69% 0.00      579 Giant                  _cv_wait+0x226
 1   2%  71% 0.00     2151 0xfffffe000228f570     selrecord+0xd8
 1   2%  74% 0.00    37062 0xfffffe0001430990     usbd_do_request_flags+0x872
 1   2%  76% 0.00      768 0xfffff8043a8cf580     uipc_send+0x8bf
 1   2%  79% 0.00      590 0xfffff8043a2046a8     uipc_send+0x927
 1   2%  81% 0.00      667 0xfffff80442e07008     vhpet_mmio_read+0x49
 1   2%  83% 0.00     2047 0xfffffe0001430990     xhci_interrupt+0x75
 1   2%  86% 0.00      986 0xfffffe0001430990     usb_process+0x167
 1   2%  88% 0.00      354 0xfffff8000de18520     seltdwait+0x78
 1   2%  90% 0.00      485 0xfffff8000d384090     usb_callback_proc+0xd9
 1   2%  93% 0.00      335 0xfffff800242b4c78     soreceive_generic+0x1c0
 1   2%  95% 0.00      601 0xfffff8006b4c4c08     ttydev_enter+0x64
 1   2%  98% 0.00     5623 0xfffff802286ff808     ttydev_enter+0x64
 1   2% 100% 0.00      423 0xfffff802286ff808     ptsdev_ioctl+0x75c

With the change:

$ sudo lockstat -e 0,1 sleep 5

Adaptive mutex spin: 1325 events in 5.031 seconds (263 events/sec)

Count indv cuml rcnt nsec Lock Caller

560  42%  42% 0.00     1111 vm page free queue     vm_page_free_toq+0xe6
558  42%  84% 0.00      937 vm page free queue     vm_page_alloc+0xbb
 51   4%  88% 0.00      687 vm active pagequeue    vm_page_enqueue+0x81
 42   3%  91% 0.00      878 vm active pagequeue    vm_page_dequeue+0x7b
 26   2%  93% 0.00     1146 vm inactive pagequeue  _vm_page_deactivate+0xf7
 19   1%  95% 0.00      823 vm inactive pagequeue  vm_page_dequeue+0x7b
 10   1%  96% 0.00      283 pmap pv chunk list     get_pv_entry+0x19c
 10   1%  96% 0.00     2405 pmap                   pmap_extract_and_hold+0xe7
  9   1%  97% 0.00      464 sellck                 doselwakeup+0x132
  4   0%  97% 0.00     9202 xhci0                  usbd_transfer_pending+0xa2
  4   0%  98% 0.00      421 process lock           trap_pfault+0x27a
  4   0%  98% 0.00     6477 USB device mutex       usbd_do_request_flags+0x5e3
  3   0%  98% 0.00      383 vm page                vm_page_rename+0xdc
  3   0%  98% 0.00      305 vm page                vm_fault_hold+0x1fad
  3   0%  99% 0.00      352 pmap pv chunk list     free_pv_chunk+0x66
  3   0%  99% 0.00     3283 Giant                  usbd_enum_lock+0x10f
  2   0%  99% 0.00      453 vm page                vm_fault_hold+0x5fb
  2   0%  99% 0.00      548 so_rcv                 soreceive_generic+0x981
  2   0%  99% 0.00      609 so_rcv                 soreceive_generic+0x1c0
  1   0%  99% 0.00      418 vm page                release_page+0xba
  1   0%  99% 0.00      216 unp_mtx                uipc_send+0x8bf
  1   0%  99% 0.00      342 ui_vmsize              swap_release_by_cred+0x149
  1   0% 100% 0.00    11922 ttymtx                 ttydev_enter+0x64
  1   0% 100% 0.00      314 vhpet lock             vhpet_mmio_read+0x49
  1   0% 100% 0.00      399 cdev                   devvn_refthread+0x9e
  1   0% 100% 0.00      353 USB device mutex       usb_callback_proc+0xd9
  1   0% 100% 0.00     1225 process lock           trap_pfault+0x1b3
  1   0% 100% 0.00     1239 process lock           ast+0x42b
  1   0% 100% 0.00      418 so_snd                 sopoll_generic+0x84

Diff Detail

Repository
rS FreeBSD src repository - subversion
Lint
Automatic diff as part of commit; lint not applicable.
Unit
Automatic diff as part of commit; unit tests not applicable.

Event Timeline

markj retitled this revision from to lockstat(1): use lock names instead of addresses.
markj edited the test plan for this revision. (Show Details)
markj added a reviewer: avg.
markj updated this object.
markj edited the test plan for this revision. (Show Details)
avg edited edge metadata.

I like this change and it (mostly) looks good to me. Thanks!
It seems that the strdup-ed lock names are not explicitly freed. Could that be a concern?

This revision is now accepted and ready to land.Sep 25 2015, 6:34 AM
In D3661#77003, @avg wrote:

...
It seems that the strdup-ed lock names are not explicitly freed. Could that be a concern?

Not really - these allocations are done once the D program is terminated and the resulting data is consumed. lockstat is a one-short sort of program and immediately exits once it has formatted its output, so there's no real leak here. It looks like it's easy to add code to free the lock names though, so I'll just do that.

This revision was automatically updated to reflect the committed changes.