| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Fri, 30 Jun 2023 15:00:02 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Steven Rostedt <rostedt@...dmis.org>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
<linux-kernel@...r.kernel.org>,
Masami Hiramatsu <mhiramat@...nel.org>,
Dave Hansen <dave.hansen@...ux.intel.com>,
"Paul E. McKenney" <paulmck@...nel.org>,
Mathieu Desnoyers <mathieu.desnoyers@...icios.com>,
Joel Fernandes <joel@...lfernandes.org>,
Peter Zijlstra <peterz@...radead.org>,
<linux-trace-kernel@...r.kernel.org>, <oliver.sang@...el.com>
Subject: [linus:master] [tracing] c2679254b9:
WARNING:at_include/trace/events/lock.h:#lock_acquired
Hello,
kernel test robot noticed "WARNING:at_include/trace/events/lock.h:#lock_acquired" on:
commit: c2679254b9c9980d9045f0f722cf093a2b1f7590 ("tracing: Make tracepoint lockdep check actually test something")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master 6aeadf7896bff4ca230702daba8788455e6b866e]
[test failed on linux-next/master 5c875096d59010cee4e00da1f9c7bdb07a025dc2]
in testcase: boot
compiler: clang-15
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
FYI, we noticed the WARNING doesn't always happen for this commit, but we never
saw it for parent. at the same time, we also saw lots of "dmesg.BUG:KCSAN"
issues for both this commit and parent.
we also noticed a WARN_ON_ONCE added in this commit, but we are not sure
the relation with the WARNNING in below table. just FYI about what we observed
in our tests.
aa69f814920d85a2 c2679254b9c9980d9045f0f722c
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
52:52 0% 52:52 dmesg.BUG:KCSAN:data-race_in#/ftrace_likely_update
52:52 0% 52:52 dmesg.BUG:KCSAN:data-race_in_ftrace_likely_update/ftrace_likely_update
:52 40% 21:52 dmesg.RIP:__warn
:52 40% 21:52 dmesg.RIP:lock_acquire
:52 40% 21:52 dmesg.RIP:lock_acquired
:52 40% 21:52 dmesg.RIP:lock_release
:52 40% 21:52 dmesg.WARNING:at_include/trace/events/error_report.h:#__warn
:52 40% 21:52 dmesg.WARNING:at_include/trace/events/lock.h:#lock_acquire
:52 40% 21:52 dmesg.WARNING:at_include/trace/events/lock.h:#lock_acquired
:52 40% 21:52 dmesg.WARNING:at_include/trace/events/lock.h:#lock_release
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 <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202306301001.c07b4084-oliver.sang@intel.com
[ 18.240313][ T0] ------------[ cut here ]------------
[ 18.240323][ T0] WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:90 lock_acquired+0x263/0x2f0
[ 18.240364][ T0] Modules linked in:
[ 18.240380][ T0] CPU: 0 PID: 0 Comm: swapper Not tainted 6.2.0-rc5-00046-gc2679254b9c9 #1 fd4e6223f7078d404e6d5a50e4281ab5a680260b
[ 18.240414][ T0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 18.240430][ T0] RIP: 0010:lock_acquired+0x263/0x2f0
[ 18.240456][ T0] Code: e0 70 02 83 f8 01 75 2a 41 0f ba e4 09 73 01 fb 48 83 c4 10 5b 41 5c 41 5d 41 5e 41 5f 5d 31 c0 31 c9 31 ff 31 d2 31 f6 c3 90 <0f> 0b 90 e9 bb fd ff ff 90 0f 0b 90 48 c7 c7 99 3e 58 83 e8 25 53
[ 18.240479][ T0] RSP: 0000:ffffffff83803520 EFLAGS: 00010046
[ 18.240502][ T0] RAX: 0000000000000000 RBX: ffffffff83a2a9f8 RCX: 0000000000000000
[ 18.240521][ T0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 18.240538][ T0] RBP: 0000000000000046 R08: 0001ffffffffffff R09: 0000000000000000
[ 18.240556][ T0] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff82b01bee
[ 18.240574][ T0] R13: 00000000ffffffff R14: ffffffff82b01bee R15: ffffffff83a2a9e0
[ 18.240593][ T0] FS: 0000000000000000(0000) GS:ffffffff8384a000(0000) knlGS:0000000000000000
[ 18.240617][ T0] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 18.240636][ T0] CR2: ffff88843ffff000 CR3: 0000000003826000 CR4: 00000000000006b0
[ 18.240658][ T0] Call Trace:
[ 18.240668][ T0] <TASK>
[ 18.240689][ T0] ? down_trylock+0xe/0x70
[ 18.240733][ T0] _raw_spin_lock_irqsave+0x93/0xb0
[ 18.240779][ T0] ? console_trylock_spinning+0x10/0x230
[ 18.240819][ T0] down_trylock+0xe/0x70
[ 18.240852][ T0] ? console_trylock_spinning+0x10/0x230
[ 18.240893][ T0] __down_trylock_console_sem+0x6a/0xf0
[ 18.240934][ T0] ? console_trylock_spinning+0x10/0x230
[ 18.240976][ T0] console_trylock+0x16/0x90
[ 18.241020][ T0] console_trylock_spinning+0x10/0x230
[ 18.241069][ T0] vprintk_emit+0x332/0x3e0
[ 18.241126][ T0] ? lock_acquire+0x175/0x1f0
[ 18.241160][ T0] vprintk_default+0x22/0x40
[ 18.241201][ T0] vprintk+0x88/0x90
[ 18.241247][ T0] _printk+0x68/0x90
[ 18.241333][ T0] report_bug+0x191/0x1d0
[ 18.241400][ T0] handle_bug+0x3e/0x70
[ 18.241436][ T0] exc_invalid_op+0x16/0x50
[ 18.241475][ T0] asm_exc_invalid_op+0x16/0x20
[ 18.241506][ T0] RIP: 0010:lock_acquire+0x175/0x1f0
[ 18.241531][ T0] Code: 83 e5 03 41 c1 e5 10 83 e3 01 c1 e3 12 42 8d 04 2b 05 00 40 08 00 89 46 30 4c 89 ff 44 89 f2 e8 81 00 00 00 e9 77 ff ff ff 90 <0f> 0b 90 e9 be fe ff ff 90 0f 0b 90 48 c7 c7 99 3e 58 83 e8 43 8b
[ 18.241554][ T0] RSP: 0000:ffffffff83803878 EFLAGS: 00010046
[ 18.241578][ T0] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 0000000000000000
[ 18.241596][ T0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 18.241613][ T0] RBP: 0000000000000000 R08: 0001ffffffffffff R09: 0000000000000000
[ 18.241631][ T0] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff813706f5
[ 18.241649][ T0] R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff83de35c0
[ 18.241678][ T0] ? kcsan_report_set_info+0x75/0x150
[ 18.241765][ T0] ? lock_acquire+0x33/0x1f0
[ 18.241799][ T0] ? disable_branch_tracing+0x70/0x70
[ 18.241846][ T0] ? kcsan_report_set_info+0x75/0x150
[ 18.241892][ T0] _raw_spin_lock_irqsave+0x65/0xb0
[ 18.241929][ T0] ? kcsan_report_set_info+0x75/0x150
[ 18.241965][ T0] ? ftrace_likely_update+0x3ab/0x3e0
[ 18.242001][ T0] kcsan_report_set_info+0x75/0x150
[ 18.242038][ T0] ? print_report+0xdc/0x450
[ 18.242099][ T0] kcsan_found_watchpoint+0xdc/0x130
[ 18.242155][ T0] ftrace_likely_update+0x3ab/0x3e0
[ 18.242183][ T0] ? default_idle_call+0x64/0xb0
[ 18.242217][ T0] ? do_idle+0xf7/0x200
[ 18.242250][ T0] ? cpu_startup_entry+0xa/0x10
[ 18.242321][ T0] delay_tsc+0x74/0x150
[ 18.242375][ T0] kcsan_setup_watchpoint+0x2be/0x4b0
[ 18.242431][ T0] ? ftrace_likely_update+0x3ab/0x3e0
[ 18.242494][ T0] ftrace_likely_update+0x3ab/0x3e0
[ 18.242521][ T0] ? ftrace_likely_update+0x3ab/0x3e0
[ 18.242548][ T0] ? kcsan_report_known_origin+0x1cd/0x200
[ 18.242622][ T0] delay_tsc+0x74/0x150
[ 18.242675][ T0] kcsan_setup_watchpoint+0x2be/0x4b0
[ 18.242733][ T0] ? ftrace_likely_update+0x81/0x3e0
[ 18.242799][ T0] ftrace_likely_update+0x81/0x3e0
[ 18.242830][ T0] ? kcsan_setup_watchpoint+0x2be/0x4b0
[ 18.242902][ T0] delay_tsc+0x86/0x150
[ 18.242955][ T0] kcsan_setup_watchpoint+0x2be/0x4b0
[ 18.243012][ T0] ? ftrace_likely_update+0x42/0x3e0
[ 18.243051][ T0] ? check_preemption_disabled+0x27/0x50
[ 18.243111][ T0] ftrace_likely_update+0x42/0x3e0
[ 18.243155][ T0] ? check_preemption_disabled+0x27/0x50
[ 18.243220][ T0] ct_kernel_exit_state+0x41/0x50
[ 18.243263][ T0] ct_kernel_exit+0x1d5/0x1f0
[ 18.243316][ T0] ct_idle_enter+0x5c/0x70
[ 18.243362][ T0] default_idle_call+0x53/0xb0
[ 18.243399][ T0] do_idle+0xf7/0x200
[ 18.243460][ T0] cpu_startup_entry+0xa/0x10
[ 18.243464][ T0] rest_init+0x274/0x280
[ 18.243464][ T0] ? time_init+0x10/0x10
[ 18.243464][ T0] arch_call_rest_init+0x5/0x10
[ 18.243464][ T0] start_kernel+0x6ac/0x700
[ 18.243464][ T0] secondary_startup_64_no_verify+0xe0/0xeb
[ 18.243464][ T0] </TASK>
[ 18.243464][ T0] irq event stamp: 8930
[ 18.243464][ T0] hardirqs last enabled at (8929): [<ffffffff82b08a26>] default_idle_call+0x76/0xb0
[ 18.243464][ T0] hardirqs last disabled at (8930): [<ffffffff8114447c>] do_idle+0x6c/0x200
[ 18.243464][ T0] softirqs last enabled at (8926): [<ffffffff82b0ac9a>] __do_softirq+0x44a/0x4c3
[ 18.243464][ T0] softirqs last disabled at (8919): [<ffffffff810e58c7>] __irq_exit_rcu+0x77/0xa0
[ 18.243464][ T0] ---[ end trace 0000000000000000 ]---
To reproduce:
# build kernel
cd linux
cp config-6.2.0-rc5-00046-gc2679254b9c9 .config
make HOSTCC=clang-15 CC=clang-15 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=clang-15 CC=clang-15 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
View attachment "config-6.2.0-rc5-00046-gc2679254b9c9" of type "text/plain" (162503 bytes)
View attachment "job-script" of type "text/plain" (4803 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (14952 bytes)
Powered by blists - more mailing lists