Re: [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference
From: Steven Rostedt
Date: Fri Nov 06 2026 - 09:27:44 EST
On Fri, 6 Nov 2026 11:07:56 +0800
kernel test robot <yi1.lai@xxxxxxxxx> wrote:
> Hello,
>
> kernel test robot noticed "WARNING:at_kernel/trace/trace_events.c:#test_double_dereference" on:
>
> commit: b5cc230af5e536ff752f8bd5c30e23612936d5c3 ("tracing: Warn when an event dereferences a pointer in TP_printk()") https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
That commit warns when there's buggy events. The bot found one.
>
> [test failed on linux-next/master ddfe51b0a0f5dc9e415cc2c8ad8db17532dd426b]
>
> in testcase: boot
>
> config: x86_64-randconfig-r2309-20261012
> compiler: gcc-14
> test machine: qemu-system-x86_64 -enable-kvm -cpu Cascadelake-Server-noTSX,enforce -smp 4 -m 16G
>
> (please refer to attached dmesg/kmsg for entire log/backtrace)
>
>
> If you fix the issue in a separate patch/commit (i.e. not just a new version of the same patch/commit), kindly add following tags
> | Reported-by: kernel test robot <yi1.lai@xxxxxxxxx>
> | Closes: https://lore.kernel.org/oe-lkp/202611060303.c90f27a7-lkp@xxxxxxxxx
>
>
> [ 0.808840][ T0] ------------[ cut here ]------------
> [ 0.810236][ T0] Event hfi1_txq_complete has double dereference in TP_printk: REC->sde ? REC->sde->this_idx : 0
Yep, it caught a bug!
ECLARE_EVENT_CLASS(/* AIP */
hfi1_ipoib_tx_template,
TP_PROTO(struct ipoib_txreq *tx, u32 idx),
TP_ARGS(tx, idx),
TP_STRUCT__entry(/* entry */
DD_DEV_ENTRY(tx->txq->priv->dd)
__field(struct ipoib_txreq *, tx)
__field(struct hfi1_ipoib_txq *, txq)
__field(struct sk_buff *, skb)
__field(ulong, idx)
),
TP_fast_assign(/* assign */
DD_DEV_ASSIGN(tx->txq->priv->dd);
__entry->tx = tx;
__entry->skb = tx->skb;
__entry->txq = tx->txq;
__entry->idx = idx;
),
TP_printk(/* print */
"[%s] tx %llx txq %llx,%u skb %llx idx %lu",
__get_str(dev),
(unsigned long long)__entry->tx,
(unsigned long long)__entry->txq,
__entry->txq ? __entry->txq->q_idx : 0,
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
You must not dereference pointers in TP_printk(). That is a bug!
I'll send a patch to fix their trace event
-- Steve
(unsigned long long)__entry->skb,
__entry->idx
)
);
> [ 0.812882][ T0] WARNING: kernel/trace/trace_events.c:417 at test_double_dereference+0x95/0x100, CPU#0: swapper/0/0
> [ 0.815697][ T0] Modules linked in:
> [ 0.816602][ T0] CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Not tainted 7.2.0-rc5+ #1 PREEMPT
> [ 0.818731][ T0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-debian-1.16.3-2 04/01/2014
> [ 0.821353][ T0] RIP: 0010:test_double_dereference (trace/trace_events.c:417 (discriminator 3))
> [ 0.822786][ T0] Code: 30 e8 c9 27 fb ff 80 7b 01 3e 75 25 e8 be 27 fb ff 48 8b 7d d0 e8 75 fa ff ff 48 89 c6 48 8d 3d 8b 30 8f 06 4c 89 e1 44 89 f2 <67> 48 0f b9 3a eb 3b e8 99 27 fb ff 41 0f b6 c7 f6 80 00 a1 fd 85
> All code
> ========
> 0: 30 e8 xor %ch,%al
> 2: c9 leave
> 3: 27 (bad)
> 4: fb sti
> 5: ff 80 7b 01 3e 75 incl 0x753e017b(%rax)
> b: 25 e8 be 27 fb and $0xfb27bee8,%eax
> 10: ff 48 8b decl -0x75(%rax)
> 13: 7d d0 jge 0xffffffffffffffe5
> 15: e8 75 fa ff ff call 0xfffffffffffffa8f
> 1a: 48 89 c6 mov %rax,%rsi
> 1d: 48 8d 3d 8b 30 8f 06 lea 0x68f308b(%rip),%rdi # 0x68f30af
> 24: 4c 89 e1 mov %r12,%rcx
> 27: 44 89 f2 mov %r14d,%edx
> 2a:* 67 48 0f b9 3a ud1 (%edx),%rdi <-- trapping instruction
> 2f: eb 3b jmp 0x6c
> 31: e8 99 27 fb ff call 0xfffffffffffb27cf
> 36: 41 0f b6 c7 movzbl %r15b,%eax
> 3a: f6 .byte 0xf6
> 3b: 80 00 a1 addb $0xa1,(%rax)
> 3e: fd std
> 3f: 85 .byte 0x85
>
> Code starting with the faulting instruction ===========================================
> 0: 67 48 0f b9 3a ud1 (%edx),%rdi
> 5: eb 3b jmp 0x42
> 7: e8 99 27 fb ff call 0xfffffffffffb27a5
> c: 41 0f b6 c7 movzbl %r15b,%eax
> 10: f6 .byte 0xf6
> 11: 80 00 a1 addb $0xa1,(%rax)
> 14: fd std
> 15: 85 .byte 0x85
> [ 0.827992][ T0] RSP: 0000:ffffffff87403d48 EFLAGS: 00010046
> [ 0.829610][ T0] RAX: ffffffff87183110 RBX: ffffffff87dcba95 RCX: ffffffff87dcba82
> [ 0.831687][ T0] RDX: 0000000000000021 RSI: ffffffff87183110 RDI: ffffffff87fe7ae0
> [ 0.833687][ T0] RBP: ffffffff87403d78 R08: 0000000000000000 R09: 0000000000000000
> [ 0.835822][ T0] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff87dcba82
> [ 0.837895][ T0] R13: ffffffff87dcbaa3 R14: 0000000000000021 R15: ffffffff87dcb92d
> [ 0.839689][ T0] FS: 0000000000000000(0000) GS:ffff8884a6e38000(0000) knlGS:0000000000000000
> [ 0.841148][ T0] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 0.842182][ T0] CR2: ffff88843ffff000 CR3: 0000000007497001 CR4: 00000000000300b0
> [ 0.843452][ T0] Call Trace:
> [ 0.843961][ T0] <TASK>
> [ 0.844424][ T0] test_event_printk (trace/trace_events.c:599)
> [ 0.845211][ T0] ? __pfx_trace_event_raw_init (trace/trace_events.c:640)
> [ 0.846111][ T0] trace_event_raw_init (trace/trace_events.c:650)
> [ 0.846904][ T0] event_init (trace/trace_events.c:3384)
> [ 0.847591][ T0] trace_event_init (trace/trace_events.c:4857 trace/trace_events.c:4950)
> [ 0.848366][ T0] trace_init (trace/trace.c:9957)
> [ 0.849014][ T0] start_kernel (main.c:1071)
> [ 0.849736][ T0] x86_64_start_reservations (x86/kernel/head64.c:310)
> [ 0.850600][ T0] x86_64_start_kernel (x86/kernel/head64.c:291)
> [ 0.851419][ T0] common_startup_64 (x86/kernel/head_64.S:418)
> [ 0.852218][ T0] </TASK>
> [ 0.852686][ T0] irq event stamp: 0
> [ 0.853291][ T0] hardirqs last enabled at (0): 0x0
> [ 0.854409][ T0] hardirqs last disabled at (0): 0x0
> [ 0.855533][ T0] softirqs last enabled at (0): 0x0
> [ 0.856645][ T0] softirqs last disabled at (0): 0x0
> [ 0.857758][ T0] ---[ end trace 0000000000000000 ]---
>
>
> The kernel config and materials to reproduce are available at:
> https://download.01.org/0day-ci/archive/20261106/202611060303.c90f27a7-lkp@xxxxxxxxx
>
>
> --
> 0-DAY CI Kernel Test Service
> https://github.com/intel/lkp-tests/wiki