[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20210427072702.GC32408@xsang-OptiPlex-9020>
Date: Tue, 27 Apr 2021 15:27:02 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
Cc: 0day robot <lkp@...el.com>, John Stultz <john.stultz@...aro.org>,
Thomas Gleixner <tglx@...utronix.de>,
Stephen Boyd <sboyd@...nel.org>,
Jonathan Corbet <corbet@....net>,
Mark Rutland <Mark.Rutland@....com>,
Marc Zyngier <maz@...nel.org>, Andi Kleen <ak@...ux.intel.com>,
Xing Zhengjun <zhengjun.xing@...ux.intel.com>,
Feng Tang <feng.tang@...el.com>,
LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
kernel-team@...com, neeraju@...eaurora.org,
zhengjun.xing@...el.com, "Paul E. McKenney" <paulmck@...nel.org>
Subject: [clocksource] 8c30ace35d:
WARNING:at_kernel/time/clocksource.c:#clocksource_watchdog
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 8c30ace35da3b362089f5c903144d762a065b58a ("[PATCH v10 clocksource 6/7] clocksource: Forgive tsc_early pre-calibration drift")
url: https://github.com/0day-ci/linux/commits/Paul-E-McKenney/Do-not-mark-clocks-unstable-due-to-delays-for-v5-13/20210426-064834
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git 2d036dfa5f10df9782f5278fc591d79d283c1fad
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>
[ 70.350923] WARNING: CPU: 0 PID: 1 at kernel/time/clocksource.c:435 clocksource_watchdog (kbuild/src/x86_64/kernel/time/clocksource.c:435)
[ 70.353152] Modules linked in:
[ 70.354074] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.12.0-rc3-00031-g8c30ace35da3 #2
[ 70.356180] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 70.358471] RIP: 0010:clocksource_watchdog (kbuild/src/x86_64/kernel/time/clocksource.c:435)
[ 70.359827] Code: 80 3d 9b 4b 89 03 00 45 89 d8 74 56 4c 8b 1d 87 4b 89 03 4c 8b 3d d8 8c dc 01 49 81 c3 60 ea 00 00 4d 39 fb 0f 89 32 fe ff ff <0f> 0b e9 2b fe ff ff 48 8b 85 80 00 00 00 48 85 c0 0f 84 52 fe ff
All code
========
0: 80 3d 9b 4b 89 03 00 cmpb $0x0,0x3894b9b(%rip) # 0x3894ba2
7: 45 89 d8 mov %r11d,%r8d
a: 74 56 je 0x62
c: 4c 8b 1d 87 4b 89 03 mov 0x3894b87(%rip),%r11 # 0x3894b9a
13: 4c 8b 3d d8 8c dc 01 mov 0x1dc8cd8(%rip),%r15 # 0x1dc8cf2
1a: 49 81 c3 60 ea 00 00 add $0xea60,%r11
21: 4d 39 fb cmp %r15,%r11
24: 0f 89 32 fe ff ff jns 0xfffffffffffffe5c
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 2b fe ff ff jmpq 0xfffffffffffffe5c
31: 48 8b 85 80 00 00 00 mov 0x80(%rbp),%rax
38: 48 85 c0 test %rax,%rax
3b: 0f .byte 0xf
3c: 84 52 fe test %dl,-0x2(%rdx)
3f: ff .byte 0xff
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 2b fe ff ff jmpq 0xfffffffffffffe32
7: 48 8b 85 80 00 00 00 mov 0x80(%rbp),%rax
e: 48 85 c0 test %rax,%rax
11: 0f .byte 0xf
12: 84 52 fe test %dl,-0x2(%rdx)
15: ff .byte 0xff
[ 70.364785] RSP: 0000:ffffb8e500003e58 EFLAGS: 00010293
[ 70.366296] RAX: 00000000005f0b1d RBX: 000000009b6490f0 RCX: 0000000000000018
[ 70.368352] RDX: 0000000000000033 RSI: 0000000039b0d3d7 RDI: 0000000000800000
[ 70.370237] RBP: ffffffffa82564c0 R08: 00000000004c4b40 R09: 00000038d59f836b
[ 70.372164] R10: 0000000000000017 R11: 00000000fffc5a70 R12: 000000383a3af27b
[ 70.373948] R13: 00000015011ba0ea R14: 00000014c76acd13 R15: 00000000fffc5e38
[ 70.375967] FS: 0000000000000000(0000) GS:ffff9fc56fc00000(0000) knlGS:0000000000000000
[ 70.378265] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 70.379942] CR2: 0000000000000000 CR3: 0000000366026000 CR4: 00000000000406f0
[ 70.381800] Call Trace:
[ 70.382655] <IRQ>
[ 70.383554] ? __clocksource_unstable (kbuild/src/x86_64/kernel/time/clocksource.c:376)
[ 70.384797] ? __clocksource_unstable (kbuild/src/x86_64/kernel/time/clocksource.c:376)
[ 70.386145] call_timer_fn (kbuild/src/x86_64/arch/x86/include/asm/jump_label.h:25 kbuild/src/x86_64/include/linux/jump_label.h:200 kbuild/src/x86_64/include/trace/events/timer.h:125 kbuild/src/x86_64/kernel/time/timer.c:1432)
[ 70.387393] run_timer_softirq (kbuild/src/x86_64/kernel/time/timer.c:1477 kbuild/src/x86_64/kernel/time/timer.c:1745 kbuild/src/x86_64/kernel/time/timer.c:1721 kbuild/src/x86_64/kernel/time/timer.c:1758)
[ 70.388616] ? lock_is_held_type (kbuild/src/x86_64/kernel/locking/lockdep.c:437 kbuild/src/x86_64/kernel/locking/lockdep.c:5550)
[ 70.389855] __do_softirq (kbuild/src/x86_64/arch/x86/include/asm/jump_label.h:25 kbuild/src/x86_64/include/linux/jump_label.h:200 kbuild/src/x86_64/include/trace/events/irq.h:142 kbuild/src/x86_64/kernel/softirq.c:346)
[ 70.390965] irq_exit_rcu (kbuild/src/x86_64/kernel/softirq.c:221 kbuild/src/x86_64/kernel/softirq.c:422 kbuild/src/x86_64/kernel/softirq.c:434)
[ 70.392198] sysvec_apic_timer_interrupt (kbuild/src/x86_64/arch/x86/kernel/apic/apic.c:1100 (discriminator 14))
[ 70.393575] </IRQ>
[ 70.394355] asm_sysvec_apic_timer_interrupt (kbuild/src/x86_64/arch/x86/include/asm/idtentry.h:632)
[ 70.395968] RIP: 0010:__memcpy (kbuild/src/x86_64/arch/x86/lib/memcpy_64.S:39)
[ 70.397140] Code: 84 00 00 00 00 00 66 90 48 89 fe 48 c7 c7 7e 0a a2 a7 e9 f1 fe ff ff cc 66 66 90 66 90 48 89 f8 48 89 d1 48 c1 e9 03 83 e2 07 <f3> 48 a5 89 d1 f3 a4 c3 66 0f 1f 44 00 00 48 89 f8 48 89 d1 f3 a4
All code
========
0: 84 00 test %al,(%rax)
2: 00 00 add %al,(%rax)
4: 00 00 add %al,(%rax)
6: 66 90 xchg %ax,%ax
8: 48 89 fe mov %rdi,%rsi
b: 48 c7 c7 7e 0a a2 a7 mov $0xffffffffa7a20a7e,%rdi
12: e9 f1 fe ff ff jmpq 0xffffffffffffff08
17: cc int3
18: 66 66 90 data16 xchg %ax,%ax
1b: 66 90 xchg %ax,%ax
1d: 48 89 f8 mov %rdi,%rax
20: 48 89 d1 mov %rdx,%rcx
23: 48 c1 e9 03 shr $0x3,%rcx
27: 83 e2 07 and $0x7,%edx
2a:* f3 48 a5 rep movsq %ds:(%rsi),%es:(%rdi) <-- trapping instruction
2d: 89 d1 mov %edx,%ecx
2f: f3 a4 rep movsb %ds:(%rsi),%es:(%rdi)
31: c3 retq
32: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
38: 48 89 f8 mov %rdi,%rax
3b: 48 89 d1 mov %rdx,%rcx
3e: f3 a4 rep movsb %ds:(%rsi),%es:(%rdi)
Code starting with the faulting instruction
===========================================
0: f3 48 a5 rep movsq %ds:(%rsi),%es:(%rdi)
3: 89 d1 mov %edx,%ecx
5: f3 a4 rep movsb %ds:(%rsi),%es:(%rdi)
7: c3 retq
8: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
e: 48 89 f8 mov %rdi,%rax
11: 48 89 d1 mov %rdx,%rcx
14: f3 a4 rep movsb %ds:(%rsi),%es:(%rdi)
[ 70.404945] RSP: 0000:ffffb8e500013ae8 EFLAGS: 00010246
[ 70.406424] RAX: ffff9fc255c00000 RBX: 0000000000001000 RCX: 0000000000000200
[ 70.408416] RDX: 0000000000000000 RSI: ffff9fc2423e4bb0 RDI: ffff9fc255c00000
[ 70.410277] RBP: ffff9fc255c00000 R08: ffff9fc140000000 R09: 0000000000004bb0
[ 70.412300] R10: ffff9fc2402a3180 R11: 0000000000000000 R12: 0000000000001000
[ 70.414194] R13: ffffb8e500013c08 R14: 0000000000001000 R15: ffffe73dc0000000
[ 70.416239] iov_iter_copy_from_user_atomic (kbuild/src/x86_64/lib/iov_iter.c:991 (discriminator 10))
[ 70.417718] generic_perform_write (kbuild/src/x86_64/mm/filemap.c:3586)
[ 70.419241] __generic_file_write_iter (kbuild/src/x86_64/mm/filemap.c:3705)
[ 70.420517] generic_file_write_iter (kbuild/src/x86_64/include/linux/fs.h:780 kbuild/src/x86_64/mm/filemap.c:3737)
[ 70.421643] __kernel_write (kbuild/src/x86_64/fs/read_write.c:550 (discriminator 1))
[ 70.422769] kernel_write (kbuild/src/x86_64/include/linux/fs.h:2903 kbuild/src/x86_64/fs/read_write.c:580 kbuild/src/x86_64/fs/read_write.c:569)
[ 70.423999] ? write_buffer (kbuild/src/x86_64/init/initramfs.c:436)
[ 70.425104] xwrite+0x31/0x62
[ 70.426262] do_copy (kbuild/src/x86_64/init/initramfs.c:394)
[ 70.427333] ? write_buffer (kbuild/src/x86_64/init/initramfs.c:436)
[ 70.428395] write_buffer (kbuild/src/x86_64/init/initramfs.c:430 (discriminator 1))
[ 70.429461] flush_buffer (kbuild/src/x86_64/init/initramfs.c:442)
[ 70.430523] ? initrd_load (kbuild/src/x86_64/init/initramfs.c:44)
[ 70.431700] __gunzip (kbuild/src/x86_64/lib/decompress_inflate.c:161)
[ 70.432696] ? bunzip2 (kbuild/src/x86_64/lib/decompress_inflate.c:39)
[ 70.433760] ? __gunzip (kbuild/src/x86_64/lib/decompress_inflate.c:207)
[ 70.434841] gunzip (kbuild/src/x86_64/lib/decompress_inflate.c:207)
[ 70.435927] ? initrd_load (kbuild/src/x86_64/init/initramfs.c:44)
[ 70.437032] unpack_to_rootfs (kbuild/src/x86_64/init/initramfs.c:500)
[ 70.438284] ? initrd_load (kbuild/src/x86_64/init/initramfs.c:44)
[ 70.439507] ? reserve_initrd_mem (kbuild/src/x86_64/init/initramfs.c:662)
[ 70.440794] populate_rootfs (kbuild/src/x86_64/init/initramfs.c:676)
[ 70.441946] ? reserve_initrd_mem (kbuild/src/x86_64/init/initramfs.c:662)
[ 70.443386] do_one_initcall (kbuild/src/x86_64/init/main.c:1226)
[ 70.444562] ? rcu_read_lock_sched_held (kbuild/src/x86_64/include/linux/lockdep.h:278 kbuild/src/x86_64/kernel/rcu/update.c:125)
[ 70.445893] kernel_init_freeable (kbuild/src/x86_64/init/main.c:1298 kbuild/src/x86_64/init/main.c:1315 kbuild/src/x86_64/init/main.c:1335 kbuild/src/x86_64/init/main.c:1537)
[ 70.447344] ? rest_init (kbuild/src/x86_64/init/main.c:1421)
[ 70.448383] kernel_init (kbuild/src/x86_64/init/main.c:1426)
[ 70.449219] ret_from_fork (kbuild/src/x86_64/arch/x86/entry/entry_64.S:300)
[ 70.450175] irq event stamp: 2300500
[ 70.451358] hardirqs last enabled at (2300510): console_unlock (kbuild/src/x86_64/arch/x86/include/asm/irqflags.h:45 (discriminator 1) kbuild/src/x86_64/arch/x86/include/asm/irqflags.h:80 (discriminator 1) kbuild/src/x86_64/arch/x86/include/asm/irqflags.h:145 (discriminator 1) kbuild/src/x86_64/kernel/printk/printk.c:2605 (discriminator 1))
[ 70.453717] hardirqs last disabled at (2300519): console_unlock (kbuild/src/x86_64/kernel/printk/printk.c:2520 (discriminator 1))
[ 70.456262] softirqs last enabled at (2299674): __do_softirq (kbuild/src/x86_64/arch/x86/include/asm/preempt.h:27 kbuild/src/x86_64/kernel/softirq.c:373)
[ 70.458585] softirqs last disabled at (2299819): irq_exit_rcu (kbuild/src/x86_64/kernel/softirq.c:221 kbuild/src/x86_64/kernel/softirq.c:422 kbuild/src/x86_64/kernel/softirq.c:434)
[ 70.461343] ---[ end trace 5049069f8395a579 ]---
[ 199.544368] Freeing initrd memory: 592780K
[ 199.545765] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 199.547432] software IO TLB: mapped [mem 0x00000000bbfe0000-0x00000000bffe0000] (64MB)
[ 199.550168] kvm: no hardware support
[ 199.551256] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x26d347b2dd9, max_idle_ns: 440795223616 ns
[ 199.563791] Initialise system trusted keyrings
[ 199.565211] Key type blacklist registered
[ 199.566840] workingset: timestamp_bits=36 max_order=22 bucket_order=0
[ 199.586726] zbud: loaded
[ 199.605246] NET: Registered protocol family 38
[ 199.606639] Key type asymmetric registered
[ 199.607761] Asymmetric key parser 'x509' registered
[ 199.609141] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[ 199.611604] io scheduler mq-deadline registered
[ 199.612900] io scheduler kyber registered
[ 199.614552] io scheduler bfq registered
[ 199.616201] atomic64_test: passed for x86-64 platform with CX8 and with SSE
[ 199.618346] start plist test
[ 199.621225] end plist test
To reproduce:
# build kernel
cd linux
cp config-5.12.0-rc3-00031-g8c30ace35da3 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> 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.12.0-rc3-00031-g8c30ace35da3" of type "text/plain" (173574 bytes)
View attachment "job-script" of type "text/plain" (4799 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (15352 bytes)
Powered by blists - more mailing lists