[PATCH] irq/tracing: Add IRQ name to irq_handler_exit tracepoint

[PATCH] irq/tracing: Add IRQ name to irq_handler_exit tracepoint

[Wander Lairson Costa]

The irq_handler_entry tracepoint includes a "name" field, which allows
for easy identification and filtering of specific IRQs. However, the
irq_handler_exit tracepoint lacks this field, making it difficult to
pair corresponding entry and exit events for analysis.

Add the "name" field to irq_handler_exit to enable consistent tracking
and correlation of IRQ entry and exit events.

Signed-off-by: Wander Lairson Costa <wander@redhat.com>
---
 include/trace/events/irq.h | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/irq.h b/include/trace/events/irq.h
index 837c1740d0d0..d705406daa37 100644
--- a/include/trace/events/irq.h
+++ b/include/trace/events/irq.h
@@ -88,16 +88,18 @@ TRACE_EVENT(irq_handler_exit,
 
 	TP_STRUCT__entry(
 		__field(	int,	irq	)
+		__string(	name,	action->name	)
 		__field(	int,	ret	)
 	),
 
 	TP_fast_assign(
 		__entry->irq	= irq;
+		__assign_str(name);
 		__entry->ret	= ret;
 	),
 
-	TP_printk("irq=%d ret=%s",
-		  __entry->irq, __entry->ret ? "handled" : "unhandled")
+	TP_printk("irq=%d name=%s ret=%s",
+		  __entry->irq, __get_str(name), __entry->ret ? "handled" : "unhandled")
 );
 
 DECLARE_EVENT_CLASS(softirq,
-- 
2.48.1

Re: [PATCH] irq/tracing: Add IRQ name to irq_handler_exit tracepoint

[Steven Rostedt]

On Thu, 30 Jan 2025 15:14:38 -0300
Wander Lairson Costa <wander@redhat.com> wrote:

> The irq_handler_entry tracepoint includes a "name" field, which allows
> for easy identification and filtering of specific IRQs. However, the
> irq_handler_exit tracepoint lacks this field, making it difficult to
> pair corresponding entry and exit events for analysis.
> 
> Add the "name" field to irq_handler_exit to enable consistent tracking
> and correlation of IRQ entry and exit events.

I'm not sure what you mean by this.


# trace-cmd record -e irq_handl* sleep 5
# trace-cmd report

          <idle>-0     [000] d.h1.  4690.628641: irq_handler_entry:    irq=55 name=virtio5-output.0
          <idle>-0     [000] d.h1.  4690.628650: irq_handler_exit:     irq=55 ret=handled
          <idle>-0     [007] d.H1.  4690.628895: irq_handler_entry:    irq=54 name=virtio5-input.0
          <idle>-0     [007] d.H1.  4690.628900: irq_handler_exit:     irq=54 ret=handled
          <idle>-0     [000] d.h1.  4690.802977: irq_handler_entry:    irq=41 name=virtio2-req.0
          <idle>-0     [000] dNh1.  4690.803046: irq_handler_exit:     irq=41 ret=handled
          <idle>-0     [000] d.h1.  4690.813958: irq_handler_entry:    irq=41 name=virtio2-req.0
          <idle>-0     [000] dNh1.  4690.814008: irq_handler_exit:     irq=41 ret=handled
          <idle>-0     [000] d.H1.  4690.814257: irq_handler_entry:    irq=41 name=virtio2-req.0
          <idle>-0     [000] dNH1.  4690.814301: irq_handler_exit:     irq=41 ret=handled
          <idle>-0     [000] d.H1.  4690.815374: irq_handler_entry:    irq=41 name=virtio2-req.0

# cat /proc/interrupts |grep -e 55 -e 54 -e 41
 41:        462          0          0          0          0          0          0          0 PCI-MSIX-0000:04:00.0   1-edge      virtio2-req.0
 54:          0          0          0          0          0          0          0       4539 PCI-MSIX-0000:07:00.0   1-edge      virtio5-input.0
 55:       4544          0          0          0          0          0          0          0 PCI-MSIX-0000:07:00.0   2-edge      virtio5-output.0
RES:       1293       1411       1357       1307       1343       1345       1330       1315   Rescheduling interrupts

We have the names right there. Heck, I could probably write a plugin for
trace-cmd to record the interrupt names in the trace.dat file and print
them out with the events. Any analysis tool could also record that.

That's better than wasting ring buffer space for every event.

-- Steve

Re: [PATCH] irq/tracing: Add IRQ name to irq_handler_exit tracepoint

[Wander Lairson Costa]

On Thu, Jan 30, 2025 at 02:07:46PM -0500, Steven Rostedt wrote:
> On Thu, 30 Jan 2025 15:14:38 -0300
> Wander Lairson Costa <wander@redhat.com> wrote:
> 
> > The irq_handler_entry tracepoint includes a "name" field, which allows
> > for easy identification and filtering of specific IRQs. However, the
> > irq_handler_exit tracepoint lacks this field, making it difficult to
> > pair corresponding entry and exit events for analysis.
> > 
> > Add the "name" field to irq_handler_exit to enable consistent tracking
> > and correlation of IRQ entry and exit events.
> 
> I'm not sure what you mean by this.
> 

What I meant was looking at the name is easier when you are analysing
several interrupts overlapping on different cores, in special if they
are shared...

> 
> # trace-cmd record -e irq_handl* sleep 5
> # trace-cmd report
> 
>           <idle>-0     [000] d.h1.  4690.628641: irq_handler_entry:    irq=55 name=virtio5-output.0
>           <idle>-0     [000] d.h1.  4690.628650: irq_handler_exit:     irq=55 ret=handled
>           <idle>-0     [007] d.H1.  4690.628895: irq_handler_entry:    irq=54 name=virtio5-input.0
>           <idle>-0     [007] d.H1.  4690.628900: irq_handler_exit:     irq=54 ret=handled
>           <idle>-0     [000] d.h1.  4690.802977: irq_handler_entry:    irq=41 name=virtio2-req.0
>           <idle>-0     [000] dNh1.  4690.803046: irq_handler_exit:     irq=41 ret=handled
>           <idle>-0     [000] d.h1.  4690.813958: irq_handler_entry:    irq=41 name=virtio2-req.0
>           <idle>-0     [000] dNh1.  4690.814008: irq_handler_exit:     irq=41 ret=handled
>           <idle>-0     [000] d.H1.  4690.814257: irq_handler_entry:    irq=41 name=virtio2-req.0
>           <idle>-0     [000] dNH1.  4690.814301: irq_handler_exit:     irq=41 ret=handled
>           <idle>-0     [000] d.H1.  4690.815374: irq_handler_entry:    irq=41 name=virtio2-req.0
> 
> # cat /proc/interrupts |grep -e 55 -e 54 -e 41
>  41:        462          0          0          0          0          0          0          0 PCI-MSIX-0000:04:00.0   1-edge      virtio2-req.0
>  54:          0          0          0          0          0          0          0       4539 PCI-MSIX-0000:07:00.0   1-edge      virtio5-input.0
>  55:       4544          0          0          0          0          0          0          0 PCI-MSIX-0000:07:00.0   2-edge      virtio5-output.0
> RES:       1293       1411       1357       1307       1343       1345       1330       1315   Rescheduling interrupts
> 
> We have the names right there. Heck, I could probably write a plugin for
> trace-cmd to record the interrupt names in the trace.dat file and print
> them out with the events. Any analysis tool could also record that.
> 
> That's better than wasting ring buffer space for every event.
> 

...But you have a point I was not considering before (ring buffer
space).

> -- Steve
>