On Wed, Feb 19, 2025 at 10:29:16AM -0500, Steven Rostedt wrote:

On Tue, 18 Feb 2025 11:50:55 -0300
Wander Lairson Costa [off-list ref] wrote:

quoted

     kworker/0:0-8       [000] b..13  2121.730643: e1000_init_hw_vf <-igbvf_reset
     kworker/0:0-8       [000] b..13  2121.730643: e1000_rar_set_vf <-e1000_init_hw_vf
     kworker/0:0-8       [000] b..13  2121.730643: e1000_write_posted_mbx <-e1000_rar_set_vf
     kworker/0:0-8       [000] D.Zf2  2121.730645: igbvf_reset_L14: (igbvf_reset+0x62/0x120 [igbvf])
     kworker/0:0-8       [000] .N...  2121.730649: igbvf_reset_L16: (igbvf_reset+0x7b/0x120 [igbvf])
  irq/63-ens14f0-1112    [000] b..12  2121.730652: igb_msix_other <-irq_thread_fn
  irq/63-ens14f0-1112    [000] b..12  2121.730652: igb_rd32 <-igb_msix_other
  irq/63-ens14f0-1112    [000] b..13  2121.730653: igb_check_for_rst <-igb_msix_other
  irq/63-ens14f0-1112    [000] b..13  2121.730653: igb_check_for_rst_pf <-igb_msix_other

quoted

This is the trace-cmd command line I ran:

$ trace-cmd start -p function -l 'e1000*' -l 'igb*' -l process_one_work -e irq:irq_handler_entry -e probe
  plugin 'function'

The threaded interrupt handler is called right after (during?)
spin_unlock_bh(). I wonder what the 'f' means in the preempt-count
field there.

The preempt count is hex, so 'f' means 15. But that that latency field looks corrupted.

After adding the probes by perf, what's the content of the format files for them?

That would likely be in /sys/kernel/tracing/events/probe/*/format

$ cd /sys/kernel/tracing/events/probe/
$ cat igbvf_reset_L1*/format
name: igbvf_reset_L14
ID: 2610
format:
        field:unsigned short common_type;       offset:0;       size:2; signed:0;
        field:unsigned char common_flags;       offset:2;       size:1; signed:0;
        field:unsigned char common_preempt_count;       offset:3;       size:1; signed:0;
        field:int common_pid;   offset:4;       size:4; signed:1;

        field:unsigned long __probe_ip; offset:8;       size:8; signed:0;

print fmt: "(%lx)", REC->__probe_ip
name: igbvf_reset_L16
ID: 2611
format:
        field:unsigned short common_type;       offset:0;       size:2; signed:0;
        field:unsigned char common_flags;       offset:2;       size:1; signed:0;
        field:unsigned char common_preempt_count;       offset:3;       size:1; signed:0;
        field:int common_pid;   offset:4;       size:4; signed:1;

        field:unsigned long __probe_ip; offset:8;       size:8; signed:0;

print fmt: "(%lx)", REC->__probe_ip

Thanks,

-- Steve