/
ppchcalls_example.txt
159 lines (132 loc) · 6.93 KB
/
ppchcalls_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
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
Demonstrations of ppchcalls, the Linux/eBPF version.
ppchcalls summarizes hcall counts across the system or a specific process,
with optional latency information. It is very useful for general workload
characterization, for example:
# ./ppchcalls.py
Tracing ppc hcalls, printing top 10... Ctrl+C to quit.
^C[04:59:47]
PPC HCALL COUNT
H_IPI 26
H_EOI 22
H_XIRR 22
H_VIO_SIGNAL 4
H_REMOVE 3
H_PUT_TCE 2
H_SEND_CRQ 2
H_STUFF_TCE 2
H_ENTER 1
H_PROTECT 1
Detaching...
#
These are the top 10 entries; you can get more by using the -T switch. Here,
the output indicates that the H_IPI, H_EOI and H_XIRR hcalls were very common,
followed immediately by H_VIO_SIGNAL, H_REMOVE and so on. By default, ppchcalls
counts across the entire system, but we can point it to a specific process of
interest:
# ./ppchcalls.py -p $(pidof vim)
Tracing ppc hcalls, printing top 10... Ctrl+C to quit.
^C[06:23:12]
PPC HCALL COUNT
H_PUT_TERM_CHAR 62
H_ENTER 2
Detaching...
#
Occasionally, the count of hcalls is not enough, and you'd also want to know
the minimum, maximum and aggregate latency for each of the hcalls:
# ./ppchcalls.py -L
Tracing ppc hcalls, printing top 10... Ctrl+C to quit.
[00:53:59]
PPC HCALL COUNT MIN (us) MAX (us) AVG (us)
H_IPI 32 0.808 7.730 2.329
H_EOI 25 0.697 1.984 1.081
H_PUT_TERM_CHAR 25 10.315 47.184 14.667
H_XIRR 25 0.868 6.223 2.397
H_VIO_SIGNAL 6 1.418 22.053 7.507
H_STUFF_TCE 3 0.865 2.349 1.384
H_SEND_CRQ 3 18.015 21.137 19.673
H_REMOVE 3 1.838 7.407 3.735
H_PUT_TCE 3 1.473 4.808 2.698
H_GET_TERM_CHAR 2 8.379 26.729 17.554
Detaching...
#
Another direction would be to understand which processes are making a lot of
hcalls, thus responsible for a lot of activity. This is what the -P switch
does:
# ./ppchcalls.py -P
Tracing ppc hcalls, printing top 10... Ctrl+C to quit.
^C[04:07:39]
PID COMM COUNT
14118 top 1073
0 [unknown] 286
1679 bash 67
14111 kworker/12:0-events_freezable_power_ 12
2 kthreadd 4
11753 kworker/0:0-events 4
141 kworker/21:0H-xfs-log/dm-0 3
847 systemd-udevd 3
14116 ppchcalls.py 3
13368 kworker/u64:1-events_unbound 3
Detaching...
#
Sometimes, you'd want both, the process making the most hcalls and respective
process-wide latencies. All you need to do is combine both options:
# ./ppchcalls.py -P -L
Tracing ppc hcalls, printing top 10... Ctrl+C to quit.
^C[04:35:27]
PID COMM COUNT MIN (us) MAX (us) AVG (us)
0 [unknown] 69 0.666 13.059 2.834
14151 kworker/12:1-events_freezable_power_ 8 6.489 84.470 34.354
11753 kworker/0:0-events 4 1.415 2.059 1.784
14152 kworker/u64:0-events_unbound 2 2.402 2.935 2.668
14154 ppchcalls.py 2 3.139 11.934 7.537
1751 sshd 1 7.227 7.227 7.227
3413 kworker/6:2-mm_percpu_wq 1 6.775 6.775 6.775
Detaching...
#
Sometimes, you'd only care about a single hcall rather than all hcalls.
Use the --hcall option for this; the following example also demonstrates
the --hcall option, for printing at predefined intervals:
# ./ppchcalls.py --hcall H_VIO_SIGNAL -i 5
hcall H_VIO_SIGNAL , hcall_nr =260
Tracing ppc hcall 'H_VIO_SIGNAL'... Ctrl+C to quit.
[04:29:56]
PPC HCALL COUNT
H_VIO_SIGNAL 6
[04:30:01]
PPC HCALL COUNT
H_VIO_SIGNAL 4
[04:30:06]
PPC HCALL COUNT
H_VIO_SIGNAL 6
[04:30:07]
PPC HCALL COUNT
Detaching...
#
USAGE:
# ./ppchcalls.py -h
usage: ppchcalls.py [-h] [-p PID] [-t TID] [-i INTERVAL] [-d DURATION]
[-T TOP] [-x] [-e ERRNO] [-L] [-m] [-P] [-l]
[--hcall HCALL]
Summarize ppc hcall counts and latencies.
optional arguments:
-h, --help show this help message and exit
-p PID, --pid PID trace only this pid
-t TID, --tid TID trace only this tid
-i INTERVAL, --interval INTERVAL
print summary at this interval (seconds)
-d DURATION, --duration DURATION
total duration of trace, in seconds
-T TOP, --top TOP print only the top hcalls by count or latency
-x, --failures trace only failed hcalls (return < 0)
-e ERRNO, --errno ERRNO
trace only hcalls that return this error (numeric or
EPERM, etc.)
-L, --latency collect hcall latency
-m, --milliseconds display latency in milliseconds (default:
microseconds)
-P, --process count by process and not by hcall
-l, --list print list of recognized hcalls and exit
--hcall HCALL trace this hcall only (use option -l to get all
recognized hcalls)
#
Ref: https://docs.kernel.org/powerpc/papr_hcalls.html