2021-01-14 07:52:40

by Bixuan Cui

[permalink] [raw]
Subject: [PATCH v2 0/2] perf tools: add 'perf irq' to measure the hardware interrupts

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' {record|report|script}

There are several variants of 'perf irq':

'perf irq record <command>' to record the irq handler events
of an arbitrary workload.

'perf irq script' to see a detailed trace of the workload that
was recorded (aliased to 'perf script' for now).

'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

-------------------------------------------------------------------------------------------------------------------------------------------
Irq name | CPU | Time consume us | Handler entry time | Handler exit time
-------------------------------------------------------------------------------------------------------------------------------------------
megasas | [0013] | 0.000003 s | 6631263.209564 s | 6631263.209567 s

-------------------------------------------------------------------------------------------------------------------------------------------
Irq name | CPU | Time consume us | Handler entry time | Handler exit time
-------------------------------------------------------------------------------------------------------------------------------------------
acpi | [0016] | 0.000018 s | 6631263.085787 s | 6631263.085805 s


And:
perf irq report --cpu 78
-------------------------------------------------------------------------------------------------------------------------------------------
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


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 | 58 ++++++
tools/perf/builtin-irq.c | 287 ++++++++++++++++++++++++++
tools/perf/builtin.h | 1 +
tools/perf/command-list.txt | 1 +
tools/perf/perf.c | 1 +
6 files changed, 349 insertions(+)
create mode 100644 tools/perf/Documentation/perf-irq.txt
create mode 100644 tools/perf/builtin-irq.c

--
2.17.1


2021-01-14 07:54:30

by Bixuan Cui

[permalink] [raw]
Subject: [PATCH v2 2/2] perf tools: Add documentation for 'perf irq' command

Add documentation for 'perf irq' command.

Signed-off-by: Bixuan Cui <[email protected]>
---
tools/perf/Documentation/perf-irq.txt | 58 +++++++++++++++++++++++++++
tools/perf/command-list.txt | 1 +
2 files changed, 59 insertions(+)
create mode 100644 tools/perf/Documentation/perf-irq.txt

diff --git a/tools/perf/Documentation/perf-irq.txt b/tools/perf/Documentation/perf-irq.txt
new file mode 100644
index 000000000000..22709b6df62d
--- /dev/null
+++ b/tools/perf/Documentation/perf-irq.txt
@@ -0,0 +1,58 @@
+perf-irq(1)
+=============
+
+NAME
+----
+perf-irq - Tool to trace/measure hardware interrupts
+
+SYNOPSIS
+--------
+[verse]
+'perf irq' {record|report|script}
+
+DESCRIPTION
+-----------
+There are several variants of 'perf irq':
+
+ 'perf irq record <command>' to record the irq handler events
+ of an arbitrary workload.
+
+ 'perf irq script' to see a detailed trace of the workload that
+ was recorded (aliased to 'perf script' for now).
+
+ '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
+
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ Irq name | CPU | Time consume us | Handler entry time | Handler exit time
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ megasas | [0013] | 0.000003 s | 6631263.209564 s | 6631263.209567 s
+
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ Irq name | CPU | Time consume us | Handler entry time | Handler exit time
+ -------------------------------------------------------------------------------------------------------------------------------------------
+ acpi | [0016] | 0.000018 s | 6631263.085787 s | 6631263.085805 s
+
+
+OPTIONS for 'perf irq report'
+----------------------------
+
+--cpus::
+ Show just entries with activities for the given CPUs.
+
+SEE ALSO
+--------
+linkperf:perf-record[1]
diff --git a/tools/perf/command-list.txt b/tools/perf/command-list.txt
index bc6c585f74fc..c5224ea3ac71 100644
--- a/tools/perf/command-list.txt
+++ b/tools/perf/command-list.txt
@@ -26,6 +26,7 @@ perf-report mainporcelain common
perf-sched mainporcelain common
perf-script mainporcelain common
perf-stat mainporcelain common
+perf-irq mainporcelain common
perf-test mainporcelain common
perf-timechart mainporcelain common
perf-top mainporcelain common
--
2.17.1

2021-01-14 09:21:14

by Alexei Budankov

[permalink] [raw]
Subject: Re: [PATCH v2 2/2] perf tools: Add documentation for 'perf irq' command


On 14.01.2021 10:48, Bixuan Cui wrote:
> Add documentation for 'perf irq' command.
>
> Signed-off-by: Bixuan Cui <[email protected]>
> ---
> tools/perf/Documentation/perf-irq.txt | 58 +++++++++++++++++++++++++++
> tools/perf/command-list.txt | 1 +
> 2 files changed, 59 insertions(+)
> create mode 100644 tools/perf/Documentation/perf-irq.txt

<SNIP>

> +
> +OPTIONS for 'perf irq report'
> +----------------------------
> +
> +--cpus::
> + Show just entries with activities for the given CPUs.

perf report mode already has -C,--cpu <num> option so
it makes sense to reuse the option for perf irq report.

Regards,
Alexei