| 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: Wed, 15 Mar 2023 13:35:27 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
Ammar Faizi <ammarfaizi2@...weeb.org>,
GNU/Weeb Mailing List <gwml@...r.gnuweeb.org>,
<linux-kernel@...r.kernel.org>
Subject: [ammarfaizi2-block:paulmck/linux-rcu/dev.2023.03.06a] [locktorture]
b5f34f7f54:
WARNING:at_kernel/locking/locktorture.c:#torture_spin_lock_write_delay
please be noted we noticed the WARNING introduced by new added WARN_ON_ONCE
in this commit.
we don't have enough knowledge if this WARNING could supply any hint for
potential problems. just made out below report FYI.
Greeting,
FYI, we noticed WARNING:at_kernel/locking/locktorture.c:#torture_spin_lock_write_delay due to commit (built with gcc-11):
commit: b5f34f7f546f7746ed4ca21da873aea5f408f295 ("locktorture: Add long_hold to adjust lock-hold delays")
https://github.com/ammarfaizi2/linux-block paulmck/linux-rcu/dev.2023.03.06a
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Link: https://lore.kernel.org/oe-lkp/202303150900.ecdd49ac-oliver.sang@intel.com
[ 47.605708][ T56] ------------[ cut here ]------------
[ 47.606397][ T1] calling map_benchmark_init+0x0/0xa7 @ 1
[ 47.606400][ T56] WARNING: CPU: 1 PID: 56 at kernel/locking/locktorture.c:208 torture_spin_lock_write_delay (locktorture.c:?)
[ 47.607291][ T1] initcall map_benchmark_init+0x0/0xa7 returned 0 after 149 usecs
[ 47.608563][ T56] Modules linked in:
[ 47.609574][ T1] calling proc_modules_init+0x0/0x4e @ 1
[ 47.610074][ T56] CPU: 1 PID: 56 Comm: lock_torture_wr Tainted: G T 6.3.0-rc1-00116-gb5f34f7f546f #6
[ 47.610763][ T1] initcall proc_modules_init+0x0/0x4e returned 0 after 17 usecs
[ 47.612095][ T56] RIP: 0010:torture_spin_lock_write_delay (locktorture.c:?)
[ 47.613007][ T1] calling timer_sysctl_init+0x0/0x4a @ 1
[ 47.617615][ T56] Code: 29 e2 e8 3e 89 00 00 48 89 ef e8 4b ff 0f 00 31 d2 69 0d eb fa f8 03 c8 00 00 00 48 63 c9 48 01 c9 48 f7 f1 48 85 d2 75 0e 90 <0f> 0b 90 bf 8e 21 00 00 e8 54 14 31 01 5b 48 89 ef 5d 41 5c e9 17
All code
========
0: 29 e2 sub %esp,%edx
2: e8 3e 89 00 00 callq 0x8945
7: 48 89 ef mov %rbp,%rdi
a: e8 4b ff 0f 00 callq 0xfff5a
f: 31 d2 xor %edx,%edx
11: 69 0d eb fa f8 03 c8 imul $0xc8,0x3f8faeb(%rip),%ecx # 0x3f8fb06
18: 00 00 00
1b: 48 63 c9 movslq %ecx,%rcx
1e: 48 01 c9 add %rcx,%rcx
21: 48 f7 f1 div %rcx
24: 48 85 d2 test %rdx,%rdx
27: 75 0e jne 0x37
29: 90 nop
2a:* 0f 0b ud2 <-- trapping instruction
2c: 90 nop
2d: bf 8e 21 00 00 mov $0x218e,%edi
32: e8 54 14 31 01 callq 0x131148b
37: 5b pop %rbx
38: 48 89 ef mov %rbp,%rdi
3b: 5d pop %rbp
3c: 41 5c pop %r12
3e: e9 .byte 0xe9
3f: 17 (bad)
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 90 nop
3: bf 8e 21 00 00 mov $0x218e,%edi
8: e8 54 14 31 01 callq 0x1311461
d: 5b pop %rbx
e: 48 89 ef mov %rbp,%rdi
11: 5d pop %rbp
12: 41 5c pop %r12
14: e9 .byte 0xe9
15: 17 (bad)
[ 47.617625][ T56] RSP: 0000:ffffc900001ebec8 EFLAGS: 00010246
[ 47.617633][ T56] RAX: 00000000001b15de RBX: 0000000000000064 RCX: 0000000000000640
[ 47.617652][ T56] RDX: 0000000000000000 RSI: 0000000097fe3ab5 RDI: ffffc900001ebee8
[ 47.617655][ T56] RBP: ffffc900001ebee8 R08: 0000000000000001 R09: 0000000000000000
[ 47.617658][ T56] R10: ffffffff83496a58 R11: 0000000000000001 R12: 0000000000000000
[ 47.617661][ T56] R13: 00000000b219b27e R14: ffff888115f024e0 R15: ffffc90000013d28
[ 47.617664][ T56] FS: 0000000000000000(0000) GS:ffff88842fd00000(0000) knlGS:0000000000000000
[ 47.617668][ T56] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 47.617671][ T56] CR2: 0000000000000000 CR3: 0000000003467000 CR4: 00000000000406a0
[ 47.617677][ T56] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 47.617680][ T56] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 47.617683][ T56] Call Trace:
[ 47.617688][ T56] <TASK>
[ 47.617707][ T56] lock_torture_writer (locktorture.c:?)
[ 47.617720][ T56] ? lock_torture_reader (locktorture.c:?)
[ 47.617725][ T56] kthread (kthread.c:?)
[ 47.617738][ T56] ? kthread_complete_and_exit (kthread.c:?)
[ 47.617745][ T56] ret_from_fork (??:?)
[ 47.617769][ T56] </TASK>
[ 47.617772][ T56] irq event stamp: 247
[ 47.617777][ T56] hardirqs last enabled at (253): console_trylock_spinning (printk.c:?)
[ 47.617787][ T56] hardirqs last disabled at (258): console_trylock_spinning (printk.c:?)
[ 47.617791][ T56] softirqs last enabled at (110): __do_softirq (??:?)
[ 47.617807][ T56] softirqs last disabled at (101): __irq_exit_rcu (softirq.c:?)
[ 47.617814][ T56] ---[ end trace 0000000000000000 ]---
[ 47.644885][ T1] initcall timer_sysctl_init+0x0/0x4a returned 0 after 143 usecs
[ 47.645944][ T1] calling timekeeping_init_ops+0x0/0x43 @ 1
[ 47.646706][ T1] initcall timekeeping_init_ops+0x0/0x43 returned 0 after 5 usecs
[ 47.647654][ T1] calling init_clocksource_sysfs+0x0/0x87 @ 1
[ 47.648772][ T1] initcall init_clocksource_sysfs+0x0/0x87 returned 0 after 378 usecs
[ 47.649802][ T1] calling init_timer_list_procfs+0x0/0x84 @ 1
[ 47.650577][ T1] initcall init_timer_list_procfs+0x0/0x84 returned 0 after 16 usecs
[ 47.651522][ T1] calling alarmtimer_init+0x0/0xec @ 1
[ 47.652331][ T1] initcall alarmtimer_init+0x0/0xec returned 0 after 105 usecs
[ 47.657746][ T1] calling clockevents_init_sysfs+0x0/0x234 @ 1
[ 47.658984][ T1] initcall clockevents_init_sysfs+0x0/0x234 returned 0 after 465 usecs
[ 47.659993][ T1] calling kallsyms_init+0x0/0x51 @ 1
[ 47.660672][ T1] initcall kallsyms_init+0x0/0x51 returned 0 after 23 usecs
[ 47.661540][ T1] calling ikconfig_init+0x0/0x8d @ 1
[ 47.662250][ T1] initcall ikconfig_init+0x0/0x8d returned 0 after 26 usecs
[ 47.663166][ T1] calling audit_watch_init+0x0/0x8b @ 1
[ 47.663905][ T1] initcall audit_watch_init+0x0/0x8b returned 0 after 45 usecs
[ 47.664844][ T1] calling audit_fsnotify_init+0x0/0x8e @ 1
[ 47.665915][ T1] initcall audit_fsnotify_init+0x0/0x8e returned 0 after 7 usecs
[ 47.666819][ T1] calling audit_tree_init+0x0/0x11d @ 1
[ 47.667490][ T1] initcall audit_tree_init+0x0/0x11d returned 0 after 11 usecs
To reproduce:
# build kernel
cd linux
cp config-6.3.0-rc1-00116-gb5f34f7f546f .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 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
View attachment "config-6.3.0-rc1-00116-gb5f34f7f546f" of type "text/plain" (146258 bytes)
View attachment "job-script" of type "text/plain" (4891 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (50868 bytes)
Powered by blists - more mailing lists