FYI, we noticed the following commit: commit: 3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91 ("x86,tsc: Feed refined TSC calibration into sched_clock") https://git.kernel.org/cgit/linux/kernel/git/peterz/queue.git sched/core in testcase: trinity with following parameters: runtime: 300s test-description: Trinity is a linux system call fuzz tester. test-url: http://codemonkey.org.uk/projects/trinity/ on test machine: qemu-system-i386 -enable-kvm -smp 2 -m 320M caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace): +-----------------------------------------------------------------------------------+------------+------------+ | | f1844e5954 | 3d2d1b9d2d | +-----------------------------------------------------------------------------------+------------+------------+ | boot_successes | 30 | 4 | | boot_failures | 2 | 30 | | invoked_oom-killer:gfp_mask=0x | 2 | 4 | | Mem-Info | 2 | 4 | | Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 2 | 4 | | INFO:rcu_preempt_detected_stalls_on_CPUs/tasks | 0 | 9 | | EIP:set_cyc2ns_scale | 0 | 7 | | INFO:rcu_sched_detected_expedited_stalls_on_CPUs/tasks:{#-...}#jiffies_s:#root:#/ | 0 | 24 | | BUG:kernel_hang_in_boot_stage | 0 | 26 | | EIP:native_safe_halt | 0 | 2 | +-----------------------------------------------------------------------------------+------------+------------+ [ 102.303164] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 102.303164] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 102.306476] (detected by 1, t=100002 jiffies, g=-100, c=-101, q=23) [ 102.306476] (detected by 1, t=100002 jiffies, g=-100, c=-101, q=23) [ 102.308165] All QSes seen, last rcu_preempt kthread activity 100002 (-197791--297793), jiffies_till_next_fqs=3, root ->qsmask 0x0 [ 102.308165] All QSes seen, last rcu_preempt kthread activity 100002 (-197791--297793), jiffies_till_next_fqs=3, root ->qsmask 0x0 [ 102.312118] swapper/1 R running task 0 0 1 0x00000000 [ 102.312118] swapper/1 R running task 0 0 1 0x00000000 [ 102.315817] Call Trace: [ 102.315817] Call Trace: [ 102.317684] sched_show_task+0xc5/0xd6 [ 102.317684] sched_show_task+0xc5/0xd6 [ 102.318621] rcu_check_callbacks+0x598/0x717 [ 102.318621] rcu_check_callbacks+0x598/0x717 [ 102.319904] update_process_times+0x28/0x4a [ 102.319904] update_process_times+0x28/0x4a [ 102.325452] tick_nohz_handler+0x95/0xd6 [ 102.325452] tick_nohz_handler+0x95/0xd6 [ 102.326426] local_apic_timer_interrupt+0x40/0x45 [ 102.326426] local_apic_timer_interrupt+0x40/0x45 [ 102.327668] smp_apic_timer_interrupt+0x33/0x42 [ 102.327668] smp_apic_timer_interrupt+0x33/0x42 [ 102.328776] apic_timer_interrupt+0x37/0x3c [ 102.328776] apic_timer_interrupt+0x37/0x3c [ 102.337498] EIP: native_safe_halt+0x5/0x7 [ 102.337498] EIP: native_safe_halt+0x5/0x7 [ 102.338509] EFLAGS: 00200246 CPU: 1 [ 102.338509] EFLAGS: 00200246 CPU: 1 [ 102.341545] EAX: 00000001 EBX: c668c840 ECX: 01000000 EDX: c17ad179 [ 102.341545] EAX: 00000001 EBX: c668c840 ECX: 01000000 EDX: c17ad179 [ 102.343252] ESI: 00000001 EDI: c66c1fb4 EBP: c66c1f4c ESP: c66c1f4c [ 102.343252] ESI: 00000001 EDI: c66c1fb4 EBP: c66c1f4c ESP: c66c1f4c [ 102.346251] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 [ 102.346251] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 [ 102.352681] default_idle+0x5a/0xd9 [ 102.352681] default_idle+0x5a/0xd9 [ 102.353511] arch_cpu_idle+0xe/0x10 [ 102.353511] arch_cpu_idle+0xe/0x10 [ 102.355846] default_idle_call+0x30/0x37 [ 102.355846] default_idle_call+0x30/0x37 [ 102.356951] do_idle+0x8f/0xfb [ 102.356951] do_idle+0x8f/0xfb [ 102.357664] cpu_startup_entry+0x1e/0x20 [ 102.357664] cpu_startup_entry+0x1e/0x20 [ 102.360040] start_secondary+0x11f/0x143 [ 102.360040] start_secondary+0x11f/0x143 [ 102.362676] startup_32_smp+0x16b/0x16d [ 102.362676] startup_32_smp+0x16b/0x16d [ 102.363583] ? startup_32_smp+0x16b/0x16d [ 102.363583] ? startup_32_smp+0x16b/0x16d [ 102.366855] rcu_preempt kthread starved for 100002 jiffies! g4294967196 c4294967195 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100 [ 102.366855] rcu_preempt kthread starved for 100002 jiffies! g4294967196 c4294967195 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100 [ 102.371855] rcu_preempt W 0 8 2 0x00000000 [ 102.371855] rcu_preempt W 0 8 2 0x00000000 [ 102.375186] Call Trace: [ 102.375186] Call Trace: [ 102.377102] __schedule+0x29a/0x512 [ 102.377102] __schedule+0x29a/0x512 [ 102.377935] schedule+0x78/0x8b [ 102.377935] schedule+0x78/0x8b [ 102.380544] schedule_timeout+0x225/0x26d [ 102.380544] schedule_timeout+0x225/0x26d [ 102.381738] ? del_timer_sync+0x41/0x41 [ 102.381738] ? del_timer_sync+0x41/0x41 [ 102.384186] rcu_gp_kthread+0x46a/0x7b8 [ 102.384186] rcu_gp_kthread+0x46a/0x7b8 [ 102.385095] kthread+0xf8/0xfd [ 102.385095] kthread+0xf8/0xfd [ 102.388478] ? force_qs_rnp+0x169/0x169 [ 102.388478] ? force_qs_rnp+0x169/0x169 [ 102.391622] ? kthread_create_on_node+0x1f/0x1f [ 102.391622] ? kthread_create_on_node+0x1f/0x1f [ 102.394154] ret_from_fork+0x21/0x2c [ 102.394154] ret_from_fork+0x21/0x2c [ 123.966184] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 102399 jiffies s: 5 root: 0x1/. [ 123.966184] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 102399 jiffies s: 5 root: 0x1/. [ 123.969178] blocking rcu_node structures: [ 123.969178] blocking rcu_node structures: [ 123.970732] Task dump for CPU 0: [ 123.970732] Task dump for CPU 0: [ 123.971986] kworker/0:1 R running task 0 20 2 0x00000000 [ 123.971986] kworker/0:1 R running task 0 20 2 0x00000000 [ 123.978939] Workqueue: events tsc_refine_calibration_work [ 123.978939] Workqueue: events tsc_refine_calibration_work [ 123.982792] Call Trace: [ 123.982792] Call Trace: [ 123.988528] ? process_one_work+0x18a/0x31a [ 123.988528] ? process_one_work+0x18a/0x31a [ 123.991864] ? worker_thread+0x236/0x30e [ 123.991864] ? worker_thread+0x236/0x30e [ 123.998041] ? kthread+0xf8/0xfd [ 123.998041] ? kthread+0xf8/0xfd [ 123.999264] ? rescuer_thread+0x26d/0x26d [ 123.999264] ? rescuer_thread+0x26d/0x26d [ 124.004894] ? kthread_create_on_node+0x1f/0x1f [ 124.004894] ? kthread_create_on_node+0x1f/0x1f [ 124.006744] ? ret_from_fork+0x21/0x2c [ 124.006744] ? ret_from_fork+0x21/0x2c [ 402.308172] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 402.308172] INFO: rcu_preempt detected stalls on CPUs/tasks: [ 402.310307] (detected by 1, t=400007 jiffies, g=-100, c=-101, q=23) [ 402.310307] (detected by 1, t=400007 jiffies, g=-100, c=-101, q=23) [ 402.311803] All QSes seen, last rcu_preempt kthread activity 400007 (102214--297793), jiffies_till_next_fqs=3, root ->qsmask 0x0 [ 402.311803] All QSes seen, last rcu_preempt kthread activity 400007 (102214--297793), jiffies_till_next_fqs=3, root ->qsmask 0x0 [ 402.314481] swapper/1 R running task 0 0 1 0x00000000 [ 402.314481] swapper/1 R running task 0 0 1 0x00000000 [ 402.316303] Call Trace: [ 402.316303] Call Trace: [ 402.316886] sched_show_task+0xc5/0xd6 [ 402.316886] sched_show_task+0xc5/0xd6 [ 402.317775] rcu_check_callbacks+0x598/0x717 [ 402.317775] rcu_check_callbacks+0x598/0x717 [ 402.318778] update_process_times+0x28/0x4a [ 402.318778] update_process_times+0x28/0x4a [ 402.319763] tick_nohz_handler+0x95/0xd6 [ 402.319763] tick_nohz_handler+0x95/0xd6 [ 402.320696] local_apic_timer_interrupt+0x40/0x45 [ 402.320696] local_apic_timer_interrupt+0x40/0x45 [ 402.322024] smp_apic_timer_interrupt+0x33/0x42 [ 402.322024] smp_apic_timer_interrupt+0x33/0x42 [ 402.323287] apic_timer_interrupt+0x37/0x3c [ 402.323287] apic_timer_interrupt+0x37/0x3c [ 402.324459] EIP: native_safe_halt+0x5/0x7 [ 402.324459] EIP: native_safe_halt+0x5/0x7 [ 402.325574] EFLAGS: 00200246 CPU: 1 [ 402.325574] EFLAGS: 00200246 CPU: 1 [ 402.326527] EAX: 00000001 EBX: c668c840 ECX: 01000000 EDX: c17ad179 [ 402.326527] EAX: 00000001 EBX: c668c840 ECX: 01000000 EDX: c17ad179 [ 402.328262] ESI: 00000001 EDI: c66c1fb4 EBP: c66c1f4c ESP: c66c1f4c [ 402.328262] ESI: 00000001 EDI: c66c1fb4 EBP: c66c1f4c ESP: c66c1f4c [ 402.329973] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 [ 402.329973] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 [ 402.331483] default_idle+0x5a/0xd9 [ 402.331483] default_idle+0x5a/0xd9 [ 402.332462] arch_cpu_idle+0xe/0x10 [ 402.332462] arch_cpu_idle+0xe/0x10 [ 402.333441] default_idle_call+0x30/0x37 [ 402.333441] default_idle_call+0x30/0x37 [ 402.335061] do_idle+0x8f/0xfb [ 402.335061] do_idle+0x8f/0xfb [ 402.335893] cpu_startup_entry+0x1e/0x20 [ 402.335893] cpu_startup_entry+0x1e/0x20 [ 402.337026] start_secondary+0x11f/0x143 [ 402.337026] start_secondary+0x11f/0x143 [ 402.339020] startup_32_smp+0x16b/0x16d [ 402.339020] startup_32_smp+0x16b/0x16d [ 402.340127] ? startup_32_smp+0x16b/0x16d [ 402.340127] ? startup_32_smp+0x16b/0x16d [ 402.341246] rcu_preempt kthread starved for 400007 jiffies! g4294967196 c4294967195 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100 [ 402.341246] rcu_preempt kthread starved for 400007 jiffies! g4294967196 c4294967195 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100 [ 402.344284] rcu_preempt W 0 8 2 0x00000000 [ 402.344284] rcu_preempt W 0 8 2 0x00000000 [ 402.345775] Call Trace: [ 402.345775] Call Trace: [ 402.346482] __schedule+0x29a/0x512 [ 402.346482] __schedule+0x29a/0x512 [ 402.347467] schedule+0x78/0x8b [ 402.347467] schedule+0x78/0x8b [ 402.348338] schedule_timeout+0x225/0x26d [ 402.348338] schedule_timeout+0x225/0x26d [ 402.349434] ? del_timer_sync+0x41/0x41 [ 402.349434] ? del_timer_sync+0x41/0x41 [ 402.350510] rcu_gp_kthread+0x46a/0x7b8 [ 402.350510] rcu_gp_kthread+0x46a/0x7b8 [ 402.351576] kthread+0xf8/0xfd [ 402.351576] kthread+0xf8/0xfd [ 402.352406] ? force_qs_rnp+0x169/0x169 [ 402.352406] ? force_qs_rnp+0x169/0x169 [ 402.353493] ? kthread_create_on_node+0x1f/0x1f [ 402.353493] ? kthread_create_on_node+0x1f/0x1f [ 402.354716] ret_from_fork+0x21/0x2c [ 402.354716] ret_from_fork+0x21/0x2c [ 431.166819] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 409599 jiffies s: 5 root: 0x1/. [ 431.166819] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 409599 jiffies s: 5 root: 0x1/. [ 431.173597] blocking rcu_node structures: [ 431.173597] blocking rcu_node structures: [ 431.174757] Task dump for CPU 0: [ 431.174757] Task dump for CPU 0: [ 431.179513] kworker/0:1 R running task 0 20 2 0x00000000 [ 431.179513] kworker/0:1 R running task 0 20 2 0x00000000 [ 431.182360] Workqueue: events tsc_refine_calibration_work [ 431.182360] Workqueue: events tsc_refine_calibration_work [ 431.183888] Call Trace: [ 431.183888] Call Trace: [ 431.184594] ? process_one_work+0x18a/0x31a [ 431.184594] ? process_one_work+0x18a/0x31a [ 431.187524] ? worker_thread+0x236/0x30e [ 431.187524] ? worker_thread+0x236/0x30e [ 431.190252] ? kthread+0xf8/0xfd [ 431.190252] ? kthread+0xf8/0xfd [ 431.191145] ? rescuer_thread+0x26d/0x26d [ 431.191145] ? rescuer_thread+0x26d/0x26d [ 431.192968] ? kthread_create_on_node+0x1f/0x1f [ 431.192968] ? kthread_create_on_node+0x1f/0x1f [ 431.194159] ? ret_from_fork+0x21/0x2c [ 431.194159] ? ret_from_fork+0x21/0x2c Elapsed time: 470 BUG: kernel hang in boot stage initrds=( /osimage/yocto/yocto-tiny-i386-2016-04-22.cgz /lkp/scheduled/vm-ivb41-yocto-i386-8/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91-20170427-25062-1vyakhz-29.cgz /lkp/lkp/lkp-i386.cgz /osimage/deps/debian-x86_64-2016-08-31.cgz/run-ipconfig.i386_2016-09-03.cgz /osimage/pkg/static/trinity-i386.cgz /pkg/linux/i386-randconfig-b0-04270810/gcc-5/3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91/modules.cgz ) cat "${initrds[@]}" > /fs/sda5/initrd-vm-ivb41-yocto-i386-8 kvm=( qemu-system-i386 -enable-kvm -kernel /pkg/linux/i386-randconfig-b0-04270810/gcc-5/3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91/vmlinuz-4.11.0-rc6-00038-g3d2d1b9 -initrd /fs/sda5/initrd-vm-ivb41-yocto-i386-8 -m 320 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -watchdog-action debug -rtc base=localtime -drive file=/fs/sda5/disk0-vm-ivb41-yocto-i386-8,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-ivb41-yocto-i386-8 -serial file:/dev/shm/kboot/vm-ivb41-yocto-i386-8/serial -serial file:/dev/shm/kboot/vm-ivb41-yocto-i386-8/kmsg -daemonize -display none -monitor null ) append=( ip=::::vm-ivb41-yocto-i386-8::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-ivb41-yocto-i386-8/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91-20170427-25062-1vyakhz-29.yaml ARCH=i386 kconfig=i386-randconfig-b0-04270810 branch=linux-devel/devel-spot-201704270425 commit=3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91 BOOT_IMAGE=/pkg/linux/i386-randconfig-b0-04270810/gcc-5/3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91/vmlinuz-4.11.0-rc6-00038-g3d2d1b9 max_uptime=1500 RESULT_ROOT=/result/trinity/300s/vm-ivb41-yocto-i386/yocto-tiny-i386-2016-04-22.cgz/i386-randconfig-b0-04270810/gcc-5/3d2d1b9d2d2fcd875a0834cbd44b208ac3695c91/29 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8 ) "${kvm[@]}" -append "${append[*]}" To reproduce: git clone https://github.com/01org/lkp-tests.git cd lkp-tests bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email Thanks, Xiaolong