* [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference
@ 2026-11-06 3:07 kernel test robot
2026-11-06 4:54 ` Masami Hiramatsu (Google)
2026-11-06 14:23 ` Steven Rostedt
0 siblings, 2 replies; 4+ messages in thread
From: kernel test robot @ 2026-11-06 3:07 UTC (permalink / raw)
To: Steven Rostedt
Cc: oe-lkp, lkp, linux-kernel, Martin Kaiser, Vinod Koul,
linux-trace-kernel, yi1.lai
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
[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@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202611060303.c90f27a7-lkp@intel.com
[ 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
[ 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@intel.com
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference
2026-11-06 3:07 [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference kernel test robot
@ 2026-11-06 4:54 ` Masami Hiramatsu (Google)
2026-11-06 14:25 ` Steven Rostedt
2026-11-06 14:23 ` Steven Rostedt
1 sibling, 1 reply; 4+ messages in thread
From: Masami Hiramatsu (Google) @ 2026-11-06 4:54 UTC (permalink / raw)
To: kernel test robot
Cc: Steven Rostedt, oe-lkp, lkp, linux-kernel, Martin Kaiser,
Vinod Koul, linux-trace-kernel
On Fri, 6 Nov 2026 11:07:56 +0800, kernel test robot <yi1.lai@intel.com> 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
>
> [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@intel.com>
> | Closes: https://lore.kernel.org/oe-lkp/202611060303.c90f27a7-lkp@intel.com
>
>
> [ 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
This seems to be expected behavior. Because "REC->sde" can point already
freed/reused object, this should not be allowed. The event must save the
sde->this_idx at TP_fast_assign() instead of recording sde.
In drivers/infiniband/hw/hfi1/trace_tx.h:
DECLARE_EVENT_CLASS(/* AIP */
hfi1_ipoib_txq_template,
...
TP_printk(/* print */
"[%s] txq %llx idx %u sde %llx:%u cpu %d head %lx tail %lx flow %x used %u stops %d no_desc %d stopped %u",
__get_str(dev),
(unsigned long long)__entry->txq,
__entry->idx,
(unsigned long long)__entry->sde,
__entry->sde ? __entry->sde->this_idx : 0, // this must be recorded as a value
__entry->sde ? __entry->sde->cpu : 0, // ditto
So this is a bug in an infiniband driver.
Thank you,
--
Masami Hiramatsu (Google) <mhiramat@kernel.org>
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference
2026-11-06 3:07 [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference kernel test robot
2026-11-06 4:54 ` Masami Hiramatsu (Google)
@ 2026-11-06 14:23 ` Steven Rostedt
1 sibling, 0 replies; 4+ messages in thread
From: Steven Rostedt @ 2026-11-06 14:23 UTC (permalink / raw)
To: kernel test robot
Cc: oe-lkp, lkp, linux-kernel, Martin Kaiser, Vinod Koul,
linux-trace-kernel
On Fri, 6 Nov 2026 11:07:56 +0800
kernel test robot <yi1.lai@intel.com> 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@intel.com>
> | Closes: https://lore.kernel.org/oe-lkp/202611060303.c90f27a7-lkp@intel.com
>
>
> [ 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@intel.com
>
>
> --
> 0-DAY CI Kernel Test Service
> https://github.com/intel/lkp-tests/wiki
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference
2026-11-06 4:54 ` Masami Hiramatsu (Google)
@ 2026-11-06 14:25 ` Steven Rostedt
0 siblings, 0 replies; 4+ messages in thread
From: Steven Rostedt @ 2026-11-06 14:25 UTC (permalink / raw)
To: Masami Hiramatsu (Google)
Cc: kernel test robot, oe-lkp, lkp, linux-kernel, Martin Kaiser,
Vinod Koul, linux-trace-kernel
On Fri, 06 Nov 2026 04:54:33 +0000
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:
> On Fri, 6 Nov 2026 11:07:56 +0800, kernel test robot <yi1.lai@intel.com> 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
> >
> > [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@intel.com>
> > | Closes: https://lore.kernel.org/oe-lkp/202611060303.c90f27a7-lkp@intel.com
> >
> >
> > [ 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
>
> This seems to be expected behavior. Because "REC->sde" can point already
> freed/reused object, this should not be allowed. The event must save the
> sde->this_idx at TP_fast_assign() instead of recording sde.
>
> In drivers/infiniband/hw/hfi1/trace_tx.h:
>
> DECLARE_EVENT_CLASS(/* AIP */
> hfi1_ipoib_txq_template,
> ...
> TP_printk(/* print */
> "[%s] txq %llx idx %u sde %llx:%u cpu %d head %lx tail %lx flow %x used %u stops %d no_desc %d stopped %u",
> __get_str(dev),
> (unsigned long long)__entry->txq,
> __entry->idx,
> (unsigned long long)__entry->sde,
> __entry->sde ? __entry->sde->this_idx : 0, // this must be recorded as a value
> __entry->sde ? __entry->sde->cpu : 0, // ditto
>
>
> So this is a bug in an infiniband driver.
Yep, I'm working on a fix, unless you are already doing it.
-- Steve
>
> Thank you,
>
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2026-11-06 14:25 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2026-11-06 3:07 [linus:master] [tracing] b5cc230af5: WARNING:at_kernel/trace/trace_events.c:#test_double_dereference kernel test robot
2026-11-06 4:54 ` Masami Hiramatsu (Google)
2026-11-06 14:25 ` Steven Rostedt
2026-11-06 14:23 ` Steven Rostedt
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox