* [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 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
* 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
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