Re: [PATCH v5 0/2] perf tools: add 'perf irq' to measure the hardware interrupts

From: Jiri Olsa
Date: Thu Feb 25 2021 - 11:22:23 EST


On Thu, Feb 25, 2021 at 09:30:14AM +0800, Bixuan Cui wrote:
> When the hardware interrupt processing function is executed, the interrupt and
> preemption of current cpu are disabled. As a result, the task is suspended.
> The execution of the hardware processing function takes a long time
> (for example 5 ms), will affect the task scheduling performance.
>
> This patches provides the 'perf irq' command to trace and calculate the time
> consumed of the hardware irq function.
>
> [verse]
> 'perf irq' [<options>] {record|report}
>
> DESCRIPTION
> -----------
> There are several variants of 'perf irq':
>
> 'perf irq record <command>' to record the irq handler events
> of an arbitrary workload.
>
> 'perf irq report' to calculate the time consumed by each
> hardware interrupt processing function.
>
> Example usage:
> perf irq record -- sleep 1
> perf irq report
>
> By default it shows the individual irq events, including the irq name,
> cpu(execute the hardware interrupt processing function), time consumed,
> entry time and exit time for the each hardware irq:
>
> -------------------------------------------------------------------------------------------------------------------------------------------
> Irq name | CPU | Time consume us | Handler entry time | Handler exit time
> -------------------------------------------------------------------------------------------------------------------------------------------
> enp2s0f2-tx-0 | [0006] | 0.000001 s | 6631263.313329 s | 6631263.313330 s
> megasas | [0013] | 0.000003 s | 6631263.209564 s | 6631263.209567 s
> acpi | [0016] | 0.000018 s | 6631263.085787 s | 6631263.085805 s
>
> And:
> perf irq --cpu 78 record -- sleep 1
> perf irq --cpu 78 report
> -------------------------------------------------------------------------------------------------------------------------------------------
> Irq name | CPU | Time consume us | Handler entry time | Handler exit time
> -------------------------------------------------------------------------------------------------------------------------------------------
> enp134s0f0-TxRx-2 | [0078] | 0.000005 s | 693757.533189 s | 693757.533194 s

hum, please yell at me if this was discussed before or I'm missing
something else, but wouldn't this be better and easier as a perf's
python script?

jirka

>
> Changes from v5:
> * Resolve conflicts by the latest commit.
>
> Changes from v4:
> * Keep pairs of irq entry/exit per cpu;
> * Add NUL-termination to the end of irq->irq_name when strncpy is used;
> * Delete some unused declarations and parameters;
>
> Changes from v3:
> * Delete 'perf irq script' because its function can be implemented using
> 'perf script';
> * Add --cpu option for 'perf irq';
>
> Changes from v2:
> * Delete "-m", "1024" in __cmd_record();
> * Change 'perf irq timeconsume <options>' to 'perf irq report <options>';
> * Fix a error for tools/perf/Documentation/perf-irq.txt;
>
> Bixuan Cui (2):
> perf tools: add 'perf irq' to measure the hardware interrupts
> perf tools: Add documentation for 'perf irq' command
>
> tools/perf/Build | 1 +
> tools/perf/Documentation/perf-irq.txt | 47 +++++
> tools/perf/builtin-irq.c | 260 ++++++++++++++++++++++++++
> tools/perf/builtin.h | 1 +
> tools/perf/command-list.txt | 1 +
> tools/perf/perf.c | 1 +
> 6 files changed, 311 insertions(+)
> create mode 100644 tools/perf/Documentation/perf-irq.txt
> create mode 100644 tools/perf/builtin-irq.c
>
> --
> 2.17.1
>