| 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
| ||
|
Message-ID: <20210318143158.GB17012@xsang-OptiPlex-9020>
Date: Thu, 18 Mar 2021 22:31:58 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Josh Don <joshdon@...gle.com>
Cc: 0day robot <lkp@...el.com>, Josh Don <joshdon@...gle.com>,
LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
Ingo Molnar <mingo@...hat.com>,
Peter Zijlstra <peterz@...radead.org>,
Juri Lelli <juri.lelli@...hat.com>,
Vincent Guittot <vincent.guittot@...aro.org>,
Dietmar Eggemann <dietmar.eggemann@....com>,
Steven Rostedt <rostedt@...dmis.org>,
Ben Segall <bsegall@...gle.com>, Mel Gorman <mgorman@...e.de>,
Daniel Bristot de Oliveira <bristot@...hat.com>,
Luis Chamberlain <mcgrof@...nel.org>,
Kees Cook <keescook@...omium.org>,
Iurii Zaikin <yzaikin@...gle.com>,
linux-fsdevel@...r.kernel.org,
David Rientjes <rientjes@...gle.com>,
Oleg Rombakh <olegrom@...gle.com>,
Paul Turner <pjt@...gle.com>, aubrey.li@...ux.intel.com,
yu.c.chen@...el.com
Subject: [sched] 663017c554: WARNING:at_kernel/sched/core.c:#scheduler_tick
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 663017c554fa0582b0109d7d5122274724a581a2 ("[PATCH] sched: Warn on long periods of pending need_resched")
url: https://github.com/0day-ci/linux/commits/Josh-Don/sched-Warn-on-long-periods-of-pending-need_resched/20210317-130220
base: https://git.kernel.org/cgit/linux/kernel/git/kees/linux.git for-next/pstore
in testcase: locktorture
version:
with following parameters:
runtime: 300s
test: cpuhotplug
test-description: This torture test consists of creating a number of kernel threads which acquire the lock and hold it for specific amount of time, thus simulating different critical region behaviors.
test-url: https://www.kernel.org/doc/Documentation/locking/locktorture.txt
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------+------------+------------+
| | 7db688e99c | 663017c554 |
+------------------------------------------------+------------+------------+
| boot_successes | 15 | 0 |
| boot_failures | 0 | 15 |
| WARNING:at_kernel/sched/core.c:#scheduler_tick | 0 | 15 |
| RIP:scheduler_tick | 0 | 15 |
| RIP:console_unlock | 0 | 6 |
| RIP:delay_tsc | 0 | 9 |
+------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 300.078613] WARNING: CPU: 1 PID: 440 at kernel/sched/core.c:4585 scheduler_tick (kbuild/src/consumer/kernel/sched/core.c:4585 kbuild/src/consumer/kernel/sched/core.c:4640)
[ 300.081225] Modules linked in: locktorture torture sr_mod cdrom intel_rapl_msr sg bochs_drm ppdev drm_vram_helper drm_ttm_helper intel_rapl_common ttm crct10dif_pclmul crc32_pclmul crc32c_intel drm_kms_helper ghash_clmulni_intel ata_generic rapl syscopyarea sysfillrect sysimgblt i2c_piix4 ipmi_devintf fb_sys_fops ipmi_msghandler ata_piix joydev drm libata serio_raw parport_pc parport ip_tables
[ 300.091527] CPU: 1 PID: 440 Comm: lock_torture_wr Not tainted 5.11.0-00004-g663017c554fa #1
[ 300.094135] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 300.096944] RIP: 0010:scheduler_tick (kbuild/src/consumer/kernel/sched/core.c:4585 kbuild/src/consumer/kernel/sched/core.c:4640)
[ 300.098878] Code: 4d 00 85 c0 74 86 4a 8b 14 ed 00 39 82 ad 48 89 d8 44 89 f6 48 c7 c7 78 91 74 ad 8b 8c 02 e8 09 00 00 4c 89 fa e8 34 d6 a6 00 <0f> 0b e9 5b ff ff ff 80 3d 37 d7 a8 01 00 0f 85 ba fe ff ff 48 c7
All code
========
0: 4d 00 85 c0 74 86 4a rex.WRB add %r8b,0x4a8674c0(%r13)
7: 8b 14 ed 00 39 82 ad mov -0x527dc700(,%rbp,8),%edx
e: 48 89 d8 mov %rbx,%rax
11: 44 89 f6 mov %r14d,%esi
14: 48 c7 c7 78 91 74 ad mov $0xffffffffad749178,%rdi
1b: 8b 8c 02 e8 09 00 00 mov 0x9e8(%rdx,%rax,1),%ecx
22: 4c 89 fa mov %r15,%rdx
25: e8 34 d6 a6 00 callq 0xa6d65e
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 5b ff ff ff jmpq 0xffffffffffffff8c
31: 80 3d 37 d7 a8 01 00 cmpb $0x0,0x1a8d737(%rip) # 0x1a8d76f
38: 0f 85 ba fe ff ff jne 0xfffffffffffffef8
3e: 48 rex.W
3f: c7 .byte 0xc7
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 5b ff ff ff jmpq 0xffffffffffffff62
7: 80 3d 37 d7 a8 01 00 cmpb $0x0,0x1a8d737(%rip) # 0x1a8d745
e: 0f 85 ba fe ff ff jne 0xfffffffffffffece
14: 48 rex.W
15: c7 .byte 0xc7
[ 300.104318] RSP: 0018:ffff9afa000c0ea0 EFLAGS: 00010086
[ 300.106365] RAX: 0000000000000000 RBX: 000000000002b040 RCX: 0000000000000027
[ 300.108888] RDX: 0000000000000027 RSI: 00000000ffff7fff RDI: ffff8e06bfd17cf8
[ 300.111662] RBP: ffff9afa000c0ed0 R08: ffff8e06bfd17cf0 R09: ffff9afa000c0cb8
[ 300.114329] R10: 0000000000000001 R11: 0000000000000001 R12: ffff8e06bfd2b040
[ 300.117088] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000003197579
[ 300.119577] FS: 0000000000000000(0000) GS:ffff8e06bfd00000(0000) knlGS:0000000000000000
[ 300.122367] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 300.125010] CR2: 0000000000442d70 CR3: 00000001381b8000 CR4: 00000000000406e0
[ 300.127199] Call Trace:
[ 300.128778] <IRQ>
[ 300.130312] update_process_times (kbuild/src/consumer/kernel/time/timer.c:1790)
[ 300.132661] tick_sched_handle+0x1f/0x60
[ 300.134782] tick_sched_timer (kbuild/src/consumer/kernel/time/tick-sched.c:1374)
[ 300.136828] ? tick_sched_do_timer (kbuild/src/consumer/kernel/time/tick-sched.c:1356)
[ 300.138519] __hrtimer_run_queues (kbuild/src/consumer/kernel/time/hrtimer.c:1519 kbuild/src/consumer/kernel/time/hrtimer.c:1583)
[ 300.140292] hrtimer_interrupt (kbuild/src/consumer/kernel/time/hrtimer.c:1648)
[ 300.142182] __sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/arch/x86/include/asm/trace/irq_vectors.h:41 kbuild/src/consumer/arch/x86/kernel/apic/apic.c:1107)
[ 300.144442] asm_call_irq_on_stack (kbuild/src/consumer/arch/x86/entry/entry_64.S:796)
[ 300.146568] </IRQ>
[ 300.148560] sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/include/asm/irq_stack.h:38 kbuild/src/consumer/arch/x86/include/asm/irq_stack.h:89 kbuild/src/consumer/arch/x86/kernel/apic/apic.c:1100)
[ 300.150589] asm_sysvec_apic_timer_interrupt (kbuild/src/consumer/arch/x86/include/asm/idtentry.h:629)
[ 300.152893] RIP: 0010:delay_tsc (kbuild/src/consumer/arch/x86/include/asm/msr.h:234 kbuild/src/consumer/arch/x86/lib/delay.c:72)
[ 300.154700] Code: 48 09 c2 49 89 d0 eb 1f 65 ff 0d 34 a8 61 53 f3 90 65 ff 05 2b a8 61 53 65 8b 35 c4 4e 61 53 41 39 f1 75 22 41 89 f1 0f 01 f9 <66> 90 48 c1 e2 20 48 09 d0 48 89 c2 4c 29 c2 48 39 fa 72 ca 65 ff
All code
========
0: 48 09 c2 or %rax,%rdx
3: 49 89 d0 mov %rdx,%r8
6: eb 1f jmp 0x27
8: 65 ff 0d 34 a8 61 53 decl %gs:0x5361a834(%rip) # 0x5361a843
f: f3 90 pause
11: 65 ff 05 2b a8 61 53 incl %gs:0x5361a82b(%rip) # 0x5361a843
18: 65 8b 35 c4 4e 61 53 mov %gs:0x53614ec4(%rip),%esi # 0x53614ee3
1f: 41 39 f1 cmp %esi,%r9d
22: 75 22 jne 0x46
24: 41 89 f1 mov %esi,%r9d
27: 0f 01 f9 rdtscp
2a:* 66 90 xchg %ax,%ax <-- trapping instruction
2c: 48 c1 e2 20 shl $0x20,%rdx
30: 48 09 d0 or %rdx,%rax
33: 48 89 c2 mov %rax,%rdx
36: 4c 29 c2 sub %r8,%rdx
39: 48 39 fa cmp %rdi,%rdx
3c: 72 ca jb 0x8
3e: 65 gs
3f: ff .byte 0xff
Code starting with the faulting instruction
===========================================
0: 66 90 xchg %ax,%ax
2: 48 c1 e2 20 shl $0x20,%rdx
6: 48 09 d0 or %rdx,%rax
9: 48 89 c2 mov %rax,%rdx
c: 4c 29 c2 sub %r8,%rdx
f: 48 39 fa cmp %rdi,%rdx
12: 72 ca jb 0xffffffffffffffde
14: 65 gs
15: ff .byte 0xff
[ 300.160663] RSP: 0018:ffff9afa0065bed0 EFLAGS: 00000246
[ 300.163199] RAX: 00000000da0561b2 RBX: 0000000000000033 RCX: 0000000000000001
[ 300.165892] RDX: 00000000000000bd RSI: 0000000000000001 RDI: 00000000002932f3
[ 300.168766] RBP: ffff9afa0065bef0 R08: 000000bdd9ea4d8d R09: 0000000000000001
[ 300.171407] R10: 0000000000000185 R11: 0000000000a1baa3 R12: ffff8e05b893a980
[ 300.174227] R13: ffffffffc0486520 R14: ffff8e05b8a30ba0 R15: ffff9afa00a9bb98
[ 300.177142] ? lock_torture_reader (kbuild/src/consumer/kernel/locking/locktorture.c:623) locktorture
[ 300.179889] torture_spin_lock_write_delay (kbuild/src/consumer/kernel/locking/locktorture.c:165 (discriminator 5)) locktorture
[ 300.182414] lock_torture_writer (kbuild/src/consumer/kernel/locking/locktorture.c:645) locktorture
[ 300.185365] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 300.187277] ? kthread_park (kbuild/src/consumer/kernel/kthread.c:245)
[ 300.189502] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
[ 300.191683] ---[ end trace 8374be259847a8ed ]---
[ 300.660870] smpboot: CPU 0 is now offline
[ 312.644235] 2021-03-18 06:09:15 rmmod locktorture
[ 312.644244]
[ 312.654928] spin_lock-torture: Stopping torture_shuffle task
[ 312.658047] spin_lock-torture: Stopping torture_shuffle
[ 312.660779] spin_lock-torture: Stopping torture_stutter
[ 312.666862] spin_lock-torture: Stopping torture_stutter task
[ 312.671159] spin_lock-torture: Stopping torture_onoff task
[ 312.673951] spin_lock-torture: Stopping torture_onoff
[ 312.678989] spin_lock-torture: Stopping lock_torture_writer task
[ 312.682047] spin_lock-torture: Stopping lock_torture_writer
[ 312.687277] spin_lock-torture: Stopping lock_torture_writer
[ 312.691345] spin_lock-torture: Stopping lock_torture_writer
[ 312.695613] spin_lock-torture: Stopping lock_torture_writer
[ 312.699827] spin_lock-torture: Stopping lock_torture_writer task
[ 312.704340] spin_lock-torture: Stopping lock_torture_writer task
[ 312.709602] spin_lock-torture: Stopping lock_torture_writer task
[ 312.713929] spin_lock-torture: Stopping lock_torture_stats task
[ 312.716148] Writes: Total: 437833814 Max/Min: 110268143/108834804 Fail: 0
[ 312.718110] spin_lock-torture: Stopping lock_torture_stats
[ 312.724378] Writes: Total: 437833814 Max/Min: 110268143/108834804 Fail: 0
[ 312.726381] spin_lock-torture:--- End of test: SUCCESS: nwriters_stress=4 nreaders_stress=0 stat_interval=60 verbose=1 shuffle_interval=3 stutter=5 shutdown_secs=0 onoff_interval=3 onoff_holdoff=30
[ 312.772639]
[ 12.556636] spin_lock-torture:--- Start of test: nwriters_stress=4 nreaders_stress=0 stat_interval=60 verbose=1 shuffle_interval=3 stutter=5 shutdown_secs=0 onoff_interval=3 onoff_holdoff=30
[ 312.772649]
[ 312.790691]
[ 12.559791] spin_lock-torture: Creating torture_onoff task
[ 312.790703]
[ 312.803821]
[ 12.569165] spin_lock-torture: torture_onoff task started
[ 312.803837]
[ 312.823428]
[ 12.569165] spin_lock-torture: Creating torture_shuffle task
[ 312.823442]
[ 312.838283]
[ 12.569170] spin_lock-torture: torture_onoff begin holdoff
[ 312.838291]
[ 312.849538]
[ 12.580144] spin_lock-torture: Creating torture_stutter task
[ 312.849549]
[ 312.859051]
[ 12.580145] spin_lock-torture: torture_shuffle task started
[ 312.859062]
[ 312.868568]
[ 12.588167] spin_lock-torture: Creating lock_torture_writer task
[ 312.868580]
[ 312.882269]
[ 12.588168] spin_lock-torture: torture_stutter task started
[ 312.882279]
To reproduce:
# build kernel
cd linux
cp config-5.11.0-00004-g663017c554fa .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
---
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.11.0-00004-g663017c554fa" of type "text/plain" (172445 bytes)
View attachment "job-script" of type "text/plain" (4571 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (17276 bytes)
View attachment "locktorture" of type "text/plain" (2729 bytes)
Powered by blists - more mailing lists