diff mbox series

irq/tracing: Add IRQ name to irq_handler_exit tracepoint

Message ID 20250130181439.58130-1-wander@redhat.com (mailing list archive)
State New
Headers show
Series irq/tracing: Add IRQ name to irq_handler_exit tracepoint | expand

Commit Message

Wander Lairson Costa Jan. 30, 2025, 6:14 p.m. UTC
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(-)

Comments

Steven Rostedt Jan. 30, 2025, 7:07 p.m. UTC | #1
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
Wander Lairson Costa Jan. 31, 2025, 12:15 p.m. UTC | #2
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
>
diff mbox series

Patch

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,