| 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 |
