Greeting, FYI, we noticed WARNING:at_kernel/sched/sched.h:#assert_clock_updated due to commit (built with gcc-11): commit: 77900e3a6934d2a2e33f26775447e1dceeb1c503 ("[PATCH v2] sched/fair: sanitize vruntime of entity being migrated") url: https://github.com/intel-lab-lkp/linux/commits/Zhang-Qiao/sched-fair-sanitize-vruntime-of-entity-being-migrated/20230306-205822 base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git 7c4a5b89a0b5a57a64b601775b296abf77a9fe97 patch link: https://lore.kernel.org/all/20230306132418.50389-1-zhangqiao22@huawei.com/ patch subject: [PATCH v2] sched/fair: sanitize vruntime of entity being migrated 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 | Link: https://lore.kernel.org/oe-lkp/202303070945.c7b65897-oliver.sang@intel.com [ 0.702980][ T1] ------------[ cut here ]------------ [ 0.704539][ T1] rq->clock_update_flags < RQCF_ACT_SKIP [ 0.704551][ T1] WARNING: CPU: 0 PID: 1 at kernel/sched/sched.h:1496 assert_clock_updated+0x21/0x24 [ 0.706944][ T1] Modules linked in: [ 0.706944][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.2.0-rc6-00112-g77900e3a6934 #11 [ 0.706944][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-5 04/01/2014 [ 0.706944][ T1] RIP: assert_clock_updated+0x21/0x24 [ 0.706944][ T1] Code: 01 85 c0 7e 03 ff 47 60 c3 83 ff 01 77 1e 80 3d 1a 1c 89 01 00 75 15 48 c7 c7 ce fd 22 82 c6 05 0a 1c 89 01 01 e8 27 ea fc ff <0f> 0b c3 0f 1f 44 00 00 41 55 41 54 49 89 fc 55 53 48 8b af 30 01 All code ======== 0: 01 85 c0 7e 03 ff add %eax,-0xfc8140(%rbp) 6: 47 60 rex.RXB (bad) 8: c3 retq 9: 83 ff 01 cmp $0x1,%edi c: 77 1e ja 0x2c e: 80 3d 1a 1c 89 01 00 cmpb $0x0,0x1891c1a(%rip) # 0x1891c2f 15: 75 15 jne 0x2c 17: 48 c7 c7 ce fd 22 82 mov $0xffffffff8222fdce,%rdi 1e: c6 05 0a 1c 89 01 01 movb $0x1,0x1891c0a(%rip) # 0x1891c2f 25: e8 27 ea fc ff callq 0xfffffffffffcea51 2a:* 0f 0b ud2 <-- trapping instruction 2c: c3 retq 2d: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1) 32: 41 55 push %r13 34: 41 54 push %r12 36: 49 89 fc mov %rdi,%r12 39: 55 push %rbp 3a: 53 push %rbx 3b: 48 rex.W 3c: 8b .byte 0x8b 3d: af scas %es:(%rdi),%eax 3e: 30 01 xor %al,(%rcx) Code starting with the faulting instruction =========================================== 0: 0f 0b ud2 2: c3 retq 3: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1) 8: 41 55 push %r13 a: 41 54 push %r12 c: 49 89 fc mov %rdi,%r12 f: 55 push %rbp 10: 53 push %rbx 11: 48 rex.W 12: 8b .byte 0x8b 13: af scas %es:(%rdi),%eax 14: 30 01 xor %al,(%rcx) [ 0.706944][ T1] RSP: 0000:ffffc90000013d28 EFLAGS: 00010082 [ 0.706944][ T1] RAX: 0000000000000000 RBX: ffff88810cba1fc0 RCX: 0000000000000003 [ 0.706944][ T1] RDX: 0000000000000105 RSI: 0000000000000001 RDI: 0000000000000001 [ 0.706944][ T1] RBP: ffff88842fc2c580 R08: 0000000000000000 R09: 0000000000000026 [ 0.706944][ T1] R10: 0000000000000000 R11: 000000002d2d2d2d R12: ffff88842fc2c600 [ 0.706944][ T1] R13: 0000000000000001 R14: 0000000000000001 R15: ffff88810cba1f40 [ 0.706944][ T1] FS: 0000000000000000(0000) GS:ffff88842fc00000(0000) knlGS:0000000000000000 [ 0.706944][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 0.706944][ T1] CR2: ffff88843ffff000 CR3: 0000000002412000 CR4: 00000000000406f0 [ 0.706944][ T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 0.706944][ T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 0.706944][ T1] Call Trace: [ 0.706944][ T1] [ 0.706944][ T1] entity_is_long_sleep+0x1b/0x38 [ 0.706944][ T1] migrate_task_rq_fair (fair.c:?) [ 0.706944][ T1] set_task_cpu (??:?) [ 0.706944][ T1] try_to_wake_up (core.c:?) [ 0.706944][ T1] ? __kthread_bind_mask (kthread.c:?) [ 0.706944][ T1] bringup_cpu (cpu.c:?) [ 0.706944][ T1] ? cpu_smt_allowed (cpu.c:?) [ 0.706944][ T1] cpuhp_invoke_callback (cpu.c:?) [ 0.706944][ T1] __cpuhp_invoke_callback_range (cpu.c:?) [ 0.706944][ T1] _cpu_up (cpu.c:?) [ 0.706944][ T1] cpu_up (cpu.c:?) [ 0.706944][ T1] bringup_nonboot_cpus (??:?) [ 0.706944][ T1] smp_init (??:?) [ 0.706944][ T1] kernel_init_freeable (main.c:?) [ 0.706944][ T1] ? rest_init (main.c:?) [ 0.706944][ T1] kernel_init (main.c:?) [ 0.706944][ T1] ret_from_fork (??:?) [ 0.706944][ T1] [ 0.706944][ T1] ---[ end trace 0000000000000000 ]--- [ 0.707026][ T1] smp: Brought up 1 node, 2 CPUs [ 0.707887][ T1] smpboot: Max logical packages: 1 [ 0.708793][ T1] smpboot: Total of 2 processors activated (8779.66 BogoMIPS) [ 0.711760][ T1] devtmpfs: initialized [ 0.711827][ T1] x86/mm: Memory block size: 128MB [ 0.716871][ T1] calling ipc_ns_init+0x0/0x18 @ 1 [ 0.717857][ T1] initcall ipc_ns_init+0x0/0x18 returned 0 after 0 usecs [ 0.718963][ T1] calling init_mmap_min_addr+0x0/0x1a @ 1 [ 0.719972][ T1] initcall init_mmap_min_addr+0x0/0x1a returned 0 after 0 usecs [ 0.721432][ T1] calling pci_realloc_setup_params+0x0/0x49 @ 1 [ 0.722492][ T1] initcall pci_realloc_setup_params+0x0/0x49 returned 0 after 0 usecs [ 0.723421][ T1] calling inet_frag_wq_init+0x0/0x41 @ 1 [ 0.726984][ T1] initcall inet_frag_wq_init+0x0/0x41 returned 0 after 4000 usecs [ 0.728809][ T1] calling e820__register_nvs_regions+0x0/0x3c @ 1 [ 0.729914][ T1] initcall e820__register_nvs_regions+0x0/0x3c returned 0 after 0 usecs [ 0.730959][ T1] calling cpufreq_register_tsc_scaling+0x0/0x2e @ 1 [ 0.732104][ T1] initcall cpufreq_register_tsc_scaling+0x0/0x2e returned 0 after 0 usecs [ 0.733576][ T1] calling cache_ap_register+0x0/0x2c @ 1 [ 0.734609][ T1] initcall cache_ap_register+0x0/0x2c returned 0 after 0 usecs [ 0.735412][ T1] calling reboot_init+0x0/0x41 @ 1 [ 0.736372][ T1] initcall reboot_init+0x0/0x41 returned 0 after 0 usecs [ 0.737551][ T1] calling init_lapic_sysfs+0x0/0x25 @ 1 [ 0.738527][ T1] initcall init_lapic_sysfs+0x0/0x25 returned 0 after 0 usecs [ 0.739387][ T1] calling alloc_frozen_cpus+0x0/0xc @ 1 [ 0.740351][ T1] initcall alloc_frozen_cpus+0x0/0xc returned 0 after 0 usecs [ 0.743426][ T1] calling cpu_hotplug_pm_sync_init+0x0/0x18 @ 1 [ 0.744547][ T1] initcall cpu_hotplug_pm_sync_init+0x0/0x18 returned 0 after 0 usecs [ 0.745965][ T1] calling wq_sysfs_init+0x0/0x2f @ 1 [ 0.746922][ T1] initcall wq_sysfs_init+0x0/0x2f returned 0 after 0 usecs [ 0.747307][ T1] calling ksysfs_init+0x0/0x9d @ 1 [ 0.748263][ T1] initcall ksysfs_init+0x0/0x9d returned 0 after 0 usecs [ 0.749522][ T1] calling schedutil_gov_init+0x0/0x15 @ 1 [ 0.750537][ T1] initcall schedutil_gov_init+0x0/0x15 returned 0 after 0 usecs [ 0.751416][ T1] calling pm_init+0x0/0x77 @ 1 [ 0.752336][ T1] initcall pm_init+0x0/0x77 returned 0 after 0 usecs [ 0.753480][ T1] calling pm_disk_init+0x0/0x1c @ 1 [ 0.754434][ T1] initcall pm_disk_init+0x0/0x1c returned 0 after 0 usecs [ 0.755378][ T1] calling swsusp_header_init+0x0/0x30 @ 1 [ 0.756414][ T1] initcall swsusp_header_init+0x0/0x30 returned 0 after 0 usecs [ 0.757816][ T1] calling rcu_set_runtime_mode+0x0/0x1b @ 1 [ 0.758858][ T1] initcall rcu_set_runtime_mode+0x0/0x1b returned 0 after 0 usecs [ 0.759395][ T1] calling init_jiffies_clocksource+0x0/0x1c @ 1 [ 0.760446][ T1] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.762235][ T1] initcall init_jiffies_clocksource+0x0/0x1c returned 0 after 0 usecs [ 0.763415][ T1] calling futex_init+0x0/0xcf @ 1 [ 0.764361][ T1] futex hash table entries: 512 (order: 3, 32768 bytes, linear) [ 0.765718][ T1] initcall futex_init+0x0/0xcf returned 0 after 0 usecs [ 0.766890][ T1] calling cgroup_wq_init+0x0/0x2d @ 1 [ 0.767275][ T1] initcall cgroup_wq_init+0x0/0x2d returned 0 after 0 usecs [ 0.768502][ T1] calling cgroup1_wq_init+0x0/0x2d @ 1 [ 0.769581][ T1] initcall cgroup1_wq_init+0x0/0x2d returned 0 after 0 usecs [ 0.770943][ T1] calling ftrace_mod_cmd_init+0x0/0x10 @ 1 [ 0.772006][ T1] initcall ftrace_mod_cmd_init+0x0/0x10 returned 0 after 0 usecs [ 0.773409][ T1] calling init_graph_trace+0x0/0x61 @ 1 [ 0.774336][ T1] initcall init_graph_trace+0x0/0x61 returned 0 after 0 usecs [ 0.778960][ T1] calling trace_events_eprobe_init_early+0x0/0x2b @ 1 [ 0.780166][ T1] initcall trace_events_eprobe_init_early+0x0/0x2b returned 0 after 0 usecs [ 0.781739][ T1] calling trace_events_synth_init_early+0x0/0x2b @ 1 [ 0.782877][ T1] initcall trace_events_synth_init_early+0x0/0x2b returned 0 after 0 usecs [ 0.783421][ T1] calling init_kprobe_trace_early+0x0/0x2a @ 1 [ 0.784494][ T1] initcall init_kprobe_trace_early+0x0/0x2a returned 0 after 0 usecs [ 0.785931][ T1] calling memory_failure_init+0x0/0x9a @ 1 [ 0.786956][ T1] initcall memory_failure_init+0x0/0x9a returned 0 after 0 usecs [ 0.788354][ T1] calling cma_init_reserved_areas+0x0/0x2f @ 1 [ 0.790834][ T1] initcall cma_init_reserved_areas+0x0/0x2f returned 0 after 0 usecs [ 0.791422][ T1] calling fsnotify_init+0x0/0x4d @ 1 [ 0.792399][ T1] initcall fsnotify_init+0x0/0x4d returned 0 after 0 usecs [ 0.793578][ T1] calling filelock_init+0x0/0xa4 @ 1 [ 0.794580][ T1] initcall filelock_init+0x0/0xa4 returned 0 after 0 usecs [ 0.795312][ T1] calling init_script_binfmt+0x0/0x1a @ 1 [ 0.796310][ T1] initcall init_script_binfmt+0x0/0x1a returned 0 after 0 usecs [ 0.797654][ T1] calling init_elf_binfmt+0x0/0x1a @ 1 [ 0.798613][ T1] initcall init_elf_binfmt+0x0/0x1a returned 0 after 0 usecs [ 0.799388][ T1] calling init_compat_elf_binfmt+0x0/0x1a @ 1 [ 0.800453][ T1] initcall init_compat_elf_binfmt+0x0/0x1a returned 0 after 0 usecs To reproduce: # build kernel cd linux cp config-6.2.0-rc6-00112-g77900e3a6934 .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= modules_install cd 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 -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