| 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: Sun, 5 Dec 2021 23:02:14 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
Cc: Neeraj Upadhyay <neeraj.iitr10@...il.com>,
LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
lkp@...el.com
Subject: [rcutorture] fbf28ca980:
WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog_cr
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: fbf28ca980766d3182971851340d9e89acd3c8c9 ("rcutorture: Combine n_max_cbs from all kthreads in a callback flood")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2021.11.30a
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):
+---------------------------------------------------------------+------------+------------+
| | 594c17c381 | fbf28ca980 |
+---------------------------------------------------------------+------------+------------+
| boot_successes | 46 | 69 |
| boot_failures | 6 | 7 |
| WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog.cold | 6 | 0 |
| RIP:rcu_torture_fwd_prog.cold | 6 | 0 |
| WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog_cr | 0 | 6 |
| RIP:rcu_torture_fwd_prog_cr | 0 | 6 |
| BUG:workqueue_lockup-pool | 0 | 1 |
+---------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 107.982759][ T108] WARNING: CPU: 1 PID: 108 at kernel/rcu/rcutorture.c:2425 rcu_torture_fwd_prog_cr (rcutorture.c:?)
[ 107.984375][ T108] Modules linked in:
[ 107.985183][ T108] CPU: 1 PID: 108 Comm: rcu_torture_fwd Not tainted 5.16.0-rc1-00108-gfbf28ca98076 #1
[ 107.986548][ T108] RIP: 0010:rcu_torture_fwd_prog_cr (rcutorture.c:?)
[ 107.987435][ T108] Code: 9f f0 02 00 48 8b 75 d0 74 19 48 8b 05 30 88 ef 02 48 8b 15 d9 de 53 01 48 2d b8 0b 00 00 48 39 d0 78 5f 49 83 fd 63 7f 04 90 <0f> 0b 90 48 8b 45 b0 48 2b 45 c0 4d 8d 04 1e 4d 89 f1 48 8b 55 c8
All code
========
0: 9f lahf
1: f0 02 00 lock add (%rax),%al
4: 48 8b 75 d0 mov -0x30(%rbp),%rsi
8: 74 19 je 0x23
a: 48 8b 05 30 88 ef 02 mov 0x2ef8830(%rip),%rax # 0x2ef8841
11: 48 8b 15 d9 de 53 01 mov 0x153ded9(%rip),%rdx # 0x153def1
18: 48 2d b8 0b 00 00 sub $0xbb8,%rax
1e: 48 39 d0 cmp %rdx,%rax
21: 78 5f js 0x82
23: 49 83 fd 63 cmp $0x63,%r13
27: 7f 04 jg 0x2d
29: 90 nop
2a:* 0f 0b ud2 <-- trapping instruction
2c: 90 nop
2d: 48 8b 45 b0 mov -0x50(%rbp),%rax
31: 48 2b 45 c0 sub -0x40(%rbp),%rax
35: 4d 8d 04 1e lea (%r14,%rbx,1),%r8
39: 4d 89 f1 mov %r14,%r9
3c: 48 8b 55 c8 mov -0x38(%rbp),%rdx
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 90 nop
3: 48 8b 45 b0 mov -0x50(%rbp),%rax
7: 48 2b 45 c0 sub -0x40(%rbp),%rax
b: 4d 8d 04 1e lea (%r14,%rbx,1),%r8
f: 4d 89 f1 mov %r14,%r9
12: 48 8b 55 c8 mov -0x38(%rbp),%rdx
[ 107.990053][ T108] RSP: 0018:ffff9af74679be70 EFLAGS: 00010293
[ 107.990896][ T108] RAX: 0000000000000000 RBX: 00000000000155ea RCX: ffff9af742880000
[ 107.991979][ T108] RDX: 0000000000000000 RSI: 000000000000000a RDI: 0000000000000002
[ 107.993064][ T108] RBP: ffff9af74679bec0 R08: ffffffffa9779de4 R09: 0000000000000000
[ 107.994168][ T108] R10: 0000000000000005 R11: 0000000000000000 R12: ffff9af746730500
[ 107.995421][ T108] R13: 0000000000000000 R14: 00000000000013fe R15: 0000000000000000
[ 107.999378][ T108] FS: 0000000000000000(0000) GS:ffff9afa6fc00000(0000) knlGS:0000000000000000
[ 108.002563][ T108] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 108.004724][ T108] CR2: 0000000000451c00 CR3: 0000000109931000 CR4: 00000000000406a0
[ 108.006439][ T108] Call Trace:
[ 108.007415][ T108] <TASK>
[ 108.008482][ T108] rcu_torture_fwd_prog.cold (rcutorture.c:?)
[ 108.010379][ T108] kthread (kthread.c:?)
[ 108.011731][ T108] ? rcu_torture_fwd_prog_cbfree (rcutorture.c:?)
[ 108.013117][ T108] ? set_kthread_struct (kthread.c:?)
[ 108.013609][ C0] random: fast init done
[ 108.014017][ T108] ret_from_fork (??:?)
[ 108.015690][ T108] </TASK>
[ 108.016159][ T108] irq event stamp: 719939
[ 108.017431][ T108] hardirqs last enabled at (719947): __up_console_sem (printk.c:?)
[ 108.019885][ T108] hardirqs last disabled at (719954): __up_console_sem (printk.c:?)
[ 108.022495][ T108] softirqs last enabled at (719928): __do_softirq (??:?)
[ 108.025442][ T108] softirqs last disabled at (719919): irq_exit_rcu (??:?)
[ 108.026864][ T108] ---[ end trace 3cd8b0ae518c7d60 ]---
[ 108.027603][ T108] rcu_torture_fwd_prog_cr Duration 1012 barrier: 71 pending 80726 n_launders: 5118 n_launders_sa: 0 n_max_gps: 0 n_max_cbs: 87530 cver 4 gps 10
[ 108.068325][ T108] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 1087 jiffies): 1s/10: 5070:7 2s/10: 49:1 3s/10: 0:1 4s/10: 0:0 5s/10: 0:0 6s/10: 0:0 7s/10: 0:0 8s/10: 0:0 9s/10: 0:0 10s/10: 0:0 11s/10: 0:0 12s/10: 0:0 13s/10: 0:0 14s/10: 0:0 15s/10: 0:0 16s/10: 0:0 17s/10: 0:0 18s/10: 0:0 19s/10: 0:0 20s/10: 0:0 21s/10: 0:0 22s/10: 0:0 23s/10: 0:0 24s/10: 0:0 25s/10: 0:0 26s/10: 0:0 27s/10: 0:0 28s/10: 0:0 29s/10: 0:0 30s/10: 0:0 31s/10: 0:0 32s/10: 0:0 33s/10: 0:0 34s/10: 0:0 35s/10: 0:0 36s/10: 0:0 37s/10: 0:0 38s/10: 0:0 39s/10: 0:0 40s/10: 0:0 41s/10: 0:0 42s/10: 0:0 43s/10: 0:0 44s/10: 0:0 45s/10: 0:0 46s/10: 0:0 47s/10: 0:0 48s/10: 0:0 49s/10: 0:0 50s/10: 0:0 51s/10: 0:0 52s/10: 0:0 53s/10: 0:0 54s/10: 0:0 55s/10: 0:0 56s/10: 0:0 57s/10: 0:0 58s/10: 0:0 59s/10: 0:0 60s/10: 0:0 61s/10: 0:0 62s/10: 0:0 63s/10: 0:0 64s/10: 0:0 65s/10: 0:0 66s/10: 0:0 67s/10: 0:0 68s/10: 0:0 69s/10: 0:0 70s/10: 0:0 71s/10: 0:0 72s/10: 0:0 73s/10: 0:0 74s/10: 0:0
[ 108.070312][ T108] 75s/10: 0:0 76s/10: 0:0 77s/10: 0:0 78s/10: 0:0 79s/10: 0:0 80s/10: 0:0 81s/10: 0:0 82s/10: 0:0 83s/10: 0:0 84s/10: 0:0 85s/10: 0:0 86s/10: 0:0 87s/10: 0:0 88s/10: 0:0 89s/10: 0:0 90s/10: 0:0 91s/10: 0:0 92s/10: 0:0 93s/10: 0:0 94s/10: 0:0 95s/10: 0:0 96s/10: 0:0 97s/10: 0:0 98s/10: 0:0 99s/10: 0:0 100s/10: 0:0 101s/10: 0:0 102s/10: 41840:599 103s/10: 45689:5
[ 110.425161][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 110.606557][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 134.105192][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 134.266983][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 157.865219][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 158.221327][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 158.495970][ T105] rcu-torture: rtc: (____ptrval____) ver: 668 tfle: 0 rta: 668 rtaf: 0 rtf: 658 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 2713 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 read-exits: 84 nocb-toggles: 0:0
[ 158.499302][ T105] rcu-torture: Reader Pipe: 3823507 184 0 0 0 0 0 0 0 0 0
[ 158.500499][ T105] rcu-torture: Reader Batch: 3822968 723 0 0 0 0 0 0 0 0 0
[ 158.501692][ T105] rcu-torture: Free-Block Circulation: 667 666 665 664 663 662 661 660 659 658 0
[ 191.083079][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 191.099494][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 211.435818][ T108] rcu_torture_fwd_prog_nr: 0 Duration 10072 cver 731 gps 2000
[ 215.072090][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 215.199784][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 219.935137][ T105] rcu-torture: rtc: (____ptrval____) ver: 1147 tfle: 0 rta: 1148 rtaf: 0 rtf: 1135 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 4019 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 read-exits: 118 nocb-toggles: 0:0
[ 219.938575][ T105] rcu-torture: Reader Pipe: 5481892 363 0 0 0 0 0 0 0 0 0
[ 219.939738][ T105] rcu-torture: Reader Batch: 5480880 1375 0 0 0 0 0 0 0 0 0
[ 219.940916][ T105] rcu-torture: Free-Block Circulation: 1147 1146 1145 1144 1143 1140 1138 1137 1136 1135 0
[ 238.175205][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 238.251671][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 261.135147][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 264.513342][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 276.256194][ T108] rcu_torture_fwd_prog n_max_cbs: 87530
[ 276.257229][ T108] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 276.664408][ T108] rcu_torture_fwd_prog_cr Duration 21 barrier: 13 pending 207 n_launders: 18179 n_launders_sa: 103 n_max_gps: 100 n_max_cbs: 11546 cver 7 gps 10
[ 276.666736][ T108] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 35 jiffies): 1s/10: 7297:4 2s/10: 15930:5 3s/10: 6498:4
[ 281.375125][ T105] rcu-torture: rtc: (____ptrval____) ver: 1654 tfle: 0 rta: 1655 rtaf: 0 rtf: 1642 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 5642 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 read-exits: 152 nocb-toggles: 0:0
[ 281.378352][ T105] rcu-torture: Reader Pipe: 7999219 468 0 0 0 0 0 0 0 0 0
[ 281.379560][ T105] rcu-torture: Reader Batch: 7997641 2046 0 0 0 0 0 0 0 0 0
[ 281.380780][ T105] rcu-torture: Free-Block Circulation: 1654 1652 1651 1650 1649 1648 1646 1645 1644 1642 0
[ 295.695160][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 296.025150][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 319.475119][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 319.755088][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 342.655116][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 342.710711][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 342.815037][ T105] rcu-torture: rtc: (____ptrval____) ver: 2147 tfle: 0 rta: 2148 rtaf: 0 rtf: 2138 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 6956 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 read-exits: 203 nocb-toggles: 0:0
[ 342.818444][ T105] rcu-torture: Reader Pipe: 9582691 649 0 0 0 0 0 0 0 0 0
[ 342.819666][ T105] rcu-torture: Reader Batch: 9580709 2631 0 0 0 0 0 0 0 0 0
[ 342.820848][ T105] rcu-torture: Free-Block Circulation: 2147 2146 2145 2144 2143 2142 2141 2140 2139 2138 0
[ 358.395405][ T108] rcu_torture_fwd_prog_nr: 0 Duration 8066 cver 632 gps 1623
[ 364.175549][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 364.205147][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 395.805395][ T109] rcu-torture: rcu_torture_read_exit: Start of episode
[ 395.904826][ T109] rcu-torture: rcu_torture_read_exit: End of episode
[ 404.255063][ T105] rcu-torture: rtc: (____ptrval____) ver: 2559 tfle: 0 rta: 2560 rtaf: 0 rtf: 2547 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 8561 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=100) barrier: 0/0:0 read-exits: 237 nocb-toggles: 0:0
[ 404.258480][ T105] rcu-torture: Reader Pipe: 11924782 763 0 0 0 0 0 0 0 0 0
[ 404.259552][ T105] rcu-torture: Reader Batch: 11922342 3203 0 0 0 0 0 0 0 0 0
[ 404.260628][ T105] rcu-torture: Free-Block Circulation: 2559 2558 2557 2556 2553 2551 2550 2549 2548 2547 0
[ 417.144155][ T579] sysrq: Emergency Sync
[ 417.145946][ T20] Emergency Sync complete
[ 417.156158][ T579] sysrq: Resetting
Kboot worker: lkp-worker06
Elapsed time: 480
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-159.cgz
-m 16384
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-snb-159::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-randconfig-r012-20211128
branch=paulmck-rcu/dev.2021.11.30a
commit=fbf28ca980766d3182971851340d9e89acd3c8c9
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r012-20211128/gcc-9/fbf28ca980766d3182971851340d9e89acd3c8c9/vmlinuz-5.16.0-rc1-00108-gfbf28ca98076
vmalloc=128M
initramfs_async=0
To reproduce:
# build kernel
cd linux
cp config-5.16.0-rc1-00108-gfbf28ca98076 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-9 CC=gcc-9 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.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
View attachment "config-5.16.0-rc1-00108-gfbf28ca98076" of type "text/plain" (142829 bytes)
View attachment "job-script" of type "text/plain" (4772 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (20200 bytes)
Powered by blists - more mailing lists