forked from iovisor/bcc
-
Notifications
You must be signed in to change notification settings - Fork 5
/
wqlat_example.txt
109 lines (89 loc) · 4.98 KB
/
wqlat_example.txt
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
Demonstrations of wqlat, the Linux eBPF/bcc version.
This tool traces work's waiting on workqueue, and records the distribution
of work's queuing latency (time), printing this as a histogram when Ctrl-C
is hit.
For example:
./wqlat
Tracing work queue request latency time... Hit Ctrl-C to end.
^C
usecs : count distribution
0 -> 1 : 530 |*************************** |
2 -> 3 : 775 |****************************************|
4 -> 7 : 387 |******************* |
8 -> 15 : 194 |********** |
16 -> 31 : 62 |*** |
32 -> 63 : 10 | |
64 -> 127 : 2 | |
128 -> 255 : 0 | |
256 -> 511 : 0 | |
512 -> 1023 : 0 | |
1024 -> 2047 : 0 | |
2048 -> 4095 : 0 | |
4096 -> 8191 : 1 | |
This example shows all kernel's work waiting latlency on workqueue. The range
of latency is from 1 millisecond to 8192 milliseconds(8ms). The bulk of
waiting latency is between 1us and 32us.The highest latency seen while tracing
is between 4 and 8 ms:the last row printed, for which there is 1 work
We can also specify the per workqueue option (-W), along with interval
and count parameters. Eg, printing out every 1 second, and including
timestamps(-T):
./wqlat -T -W 1 2
Tracing work queue request latency time... Hit Ctrl-C to end.
06:14:55
wqname = xfs-cil/dm-4
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 1 |****************************************|
4 -> 7 : 1 |****************************************|
8 -> 15 : 1 |****************************************|
[...]
06:14:56
wqname = events_power_efficient
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 2 |************************** |
8 -> 15 : 3 |****************************************|
16 -> 31 : 1 |************* |
[...]
An tracing one workqueue (-w) can be specified, along with interval
and count. Eg, printing output every 1 second, and including Timestamps(-T)
and workqueue nvmet_tcp_wq:
./wqlat -T -w nvmet_tcp_wq 1 2
Tracing work queue request latency time... Hit Ctrl-C to end.
06:18:03
usecs : count distribution
0 -> 1 : 245 |************************* |
2 -> 3 : 377 |****************************************|
4 -> 7 : 76 |******** |
8 -> 15 : 29 |*** |
16 -> 31 : 8 | |
32 -> 63 : 5 | |
06:18:04
usecs : count distribution
0 -> 1 : 547 |********************************** |
2 -> 3 : 629 |****************************************|
4 -> 7 : 83 |***** |
8 -> 15 : 23 |* |
16 -> 31 : 5 | |
32 -> 63 : 4 | |
USAGE message:
./wqlat -h
usage: wqlat [-h] [-T] [-N] [-W] [-w WQNAME] [interval] [count]
Summarize workqueue request latency as histograms.
positional arguments:
interval output interval, in seconds
count number of outputs
optional arguments:
-h, --help show this help message and exit
-T, --timestamp include timestamp on output
-N, --nanoseconds output in nanoseconds
-W, --workqueues print a histogram per work queue
-w WQNAME, --wqname WQNAME
print this workqueue only
examples:
./wqlat # summarize workqueue latency as a histogram
./wqlat 1 10 # print 1 second summaries, 10 times
./wqlat -W 1 10 # print 1 second, 10 times per workqueue
./wqlat -NT 1 # 1s summaries, nanoseconds, and timestamps
./wqlat -w nvmet_tcp_wq 1 # 1s summaries for workqueue nvmet_tcp_wq