klockstat(8) System Manager's Manual klockstat(8)

# [NAME](#NAME)

klockstat - Traces kernel mutex lock events and display locks statistics. Uses Linux eBPF/bcc.

# [SYNOPSIS](#SYNOPSIS)

**klockstat \[-h] \[-i] \[-n] \[-s] \[-c] \[-S FIELDS] \[-p] \[-t] \[-d DURATION]**

# [DESCRIPTION](#DESCRIPTION)

klockstat traces kernel mutex lock events and display locks statistics and displays following data:

Caller Avg Spin Count Max spin Total spin  
psi\_avgs\_work+0x2e 3675 5 5468 18379  
flush\_to\_ldisc+0x22 2833 2 4210 5667  
n\_tty\_write+0x30c 3914 1 3914 3914  
isig+0x5d 2390 1 2390 2390  
tty\_buffer\_flush+0x2a 1604 1 1604 1604  
commit\_echoes+0x22 1400 1 1400 1400  
n\_tty\_receive\_buf\_common+0x3b9 1399 1 1399 1399

Caller Avg Hold Count Max hold Total hold  
flush\_to\_ldisc+0x22 42558 2 76135 85116  
psi\_avgs\_work+0x2e 14821 5 20446 74106  
n\_tty\_receive\_buf\_common+0x3b9 12300 1 12300 12300  
n\_tty\_write+0x30c 10712 1 10712 10712  
isig+0x5d 3362 1 3362 3362  
tty\_buffer\_flush+0x2a 3078 1 3078 3078  
commit\_echoes+0x22 3017 1 3017 3017

Every caller to using kernel's mutex is displayed on every line.

First portion of lines show the lock acquiring data, showing the amount of time it took to acquired given lock.

'Caller' - symbol acquiring the mutex  
'Average Spin' - average time to acquire the mutex  
'Count' - number of times mutex was acquired  
'Max spin' - maximum time to acquire the mutex  
'Total spin' - total time spent in acquiring the mutex

Second portion of lines show the lock holding data, showing the amount of time it took to hold given lock.

'Caller' - symbol holding the mutex  
'Average Hold' - average time mutex was held  
'Count' - number of times mutex was held  
'Max hold' - maximum time mutex was held  
'Total hold' - total time spent in holding the mutex

This works by tracing mutex\_lock/unlock kprobes, updating the lock stats in maps and processing them in the python part.

Since this uses BPF, only the root user can use this tool.

# [REQUIREMENTS](#REQUIREMENTS)

CONFIG\_BPF and bcc.

# [OPTIONS](#OPTIONS)

[-h](#h)

Print usage message.

[-i SEC](#i)

print summary at this interval (seconds)

[-c CALLER](#c)

print locks taken by given caller filter (e.g., pipe\_)

[-S FIELDS](#S)

sort data on specific columns defined by FIELDS string (by default the data is sorted by Max columns)

FIELDS string contains 1 or 2 fields describing columns to sort on for both acquiring and holding data. Following fields are available:

acq\_max for 'Max spin' column  
acq\_total for 'Total spin' column  
acq\_count for 'Count' column

hld\_max for 'Max hold' column  
hld\_total for 'Total hold' column  
hld\_count for 'Count' column

See EXAMPLES.

[-n COUNT](#n)

print COUNT number of locks

[-s COUNT](#s)

print COUNT number of stack entries

[-p PID](#p)

Trace this process ID only (filtered in-kernel).

[-t TID](#t)

Trace this thread ID only (filtered in-kernel).

[-d DURATION](#d)

Total duration of trace in seconds.

[--stack-storage-size STACK\_STORAGE\_SIZE](#stack_storage_size)

Change the number of unique stack traces that can be stored and displayed.

# [EXAMPLES](#EXAMPLES)

[Sort lock acquired results on acquired count:](#Sort)

\# **klockstat -S acq\_count**

[Sort lock held results on total held time:](#Sort~2)

\# **klockstat -S hld\_total**

[Combination of above:](#Combination)

\# **klockstat -S acq\_count,hld\_total**

[Trace system wide:](#Trace)

\# **klockstat**

[Trace for 5 seconds only:](#Trace~2)

\# **klockstat -d 5**

[Display stats every 5 seconds](#Display)

\# **klockstat -i 5**

[Trace locks for PID 123:](#Trace~3)

\# **klockstat -p 123**

[Trace locks for TID 321:](#Trace~4)

\# **klockstat -t 321**

[Display stats only for lock callers with 'pipe\_' substring](#Display~2)

\# **klockstat -c pipe\_**

[Display 3 locks:](#Display~3)

\# **klockstat -n 3**

[Display 10 levels of stack for the most expensive lock:](#Display~4)

\# **klockstat -n 1 -s 10**

Tracing lock events... Hit Ctrl-C to end. ^C  
Caller Avg Spin Count Max spin Total spin  
pipe\_wait+0xa9 670 397691 17273 266775437  
pipe\_wait+0xa9  
pipe\_read+0x206  
new\_sync\_read+0x12a  
vfs\_read+0x9d  
ksys\_read+0x5f  
do\_syscall\_64+0x5b  
entry\_SYSCALL\_64\_after\_hwframe+0x44

Caller Avg Hold Count Max hold Total hold  
flush\_to\_ldisc+0x22 28381 3 65484 85144  
flush\_to\_ldisc+0x22  
process\_one\_work+0x1b0  
worker\_thread+0x50  
kthread+0xfb  
ret\_from\_fork+0x35

# [SOURCE](#SOURCE)

This is from bcc.

https://github.com/iovisor/bcc

Also look in the bcc distribution for a companion \_examples.txt file containing example usage, output, and commentary for this tool.

# [OS](#OS)

Linux

# [STABILITY](#STABILITY)

Unstable - in development.

# [CREDITS](#CREDITS)

This tool is based on work of David Valin <dvalin@redhat.com> and his script.

# [AUTHOR](#AUTHOR)

Jiri Olsa

2019-10-22 USER COMMANDS

---

Document: klockstat(8) from bcc 0.37.0-r2 (Chainguard OS)
Source: https://github.com/iovisor/bcc