Re: [PATCH 2/2] tick: Make sure tick timer is active when bypassing reprogramming

[Levin, Alexander (Sasha Levin)]

On Fri, Apr 21, 2017 at 04:00:55PM +0200, Frederic Weisbecker wrote:
> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> index 502b320..be7ca4d 100644
> --- a/kernel/time/tick-sched.c
> +++ b/kernel/time/tick-sched.c
> @@ -783,8 +783,13 @@ static ktime_t tick_nohz_stop_sched_tick(struct tick_sched *ts,
>  	tick = expires;
>  
>  	/* Skip reprogram of event if its not changed */
> -	if (ts->tick_stopped && (expires == ts->next_tick))
> -		goto out;
> +	if (ts->tick_stopped && (expires == ts->next_tick)) {
> +		/* Sanity check: make sure clockevent is actually programmed */
> +		if (likely(dev->next_event <= ts->next_tick))
> +			goto out;
> +
> +		WARN_ON_ONCE(1);
> +	}

I seem to be hitting that in a KVM vm, even without load (sometimes
right after boot):

------------[ cut here ]------------
WARNING: CPU: 5 PID: 0 at kernel/time/tick-sched.c:794 tick_nohz_stop_sched_tick kernel/time/tick-sched.c:791 [inline]
WARNING: CPU: 5 PID: 0 at kernel/time/tick-sched.c:794 __tick_nohz_idle_enter+0x11f4/0x1ab0 kernel/time/tick-sched.c:950
Kernel panic - not syncing: panic_on_warn set ...

CPU: 5 PID: 0 Comm: swapper/5 Not tainted 4.12.0-rc3-next-20170601+ #53
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.1-1ubuntu1 04/01/2014
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:16 [inline]
 dump_stack+0x115/0x1d1 lib/dump_stack.c:52
 panic+0x1d8/0x3c4 kernel/panic.c:180
 __warn+0x1d6/0x220 kernel/panic.c:541
 report_bug+0x223/0x310 lib/bug.c:183
 fixup_bug arch/x86/kernel/traps.c:190 [inline]
 do_trap_no_signal arch/x86/kernel/traps.c:224 [inline]
 do_trap+0x34c/0x490 arch/x86/kernel/traps.c:273
 do_error_trap+0x12f/0x390 arch/x86/kernel/traps.c:310
 do_invalid_op+0x1b/0x20 arch/x86/kernel/traps.c:323
 invalid_op+0x1e/0x30 arch/x86/entry/entry_64.S:844
RIP: 0010:tick_nohz_stop_sched_tick kernel/time/tick-sched.c:791 [inline]
RIP: 0010:__tick_nohz_idle_enter+0x11f4/0x1ab0 kernel/time/tick-sched.c:950
RSP: 0018:ffff88005f407dd8 EFLAGS: 00010082
RAX: 000000000000007e RBX: ffff88005f5dcfe0 RCX: 0000000000000000
RDX: 000000000000007e RSI: 1ffff1000be80f78 RDI: ffffed000be80faf
RBP: ffff88005f407f88 R08: ffff88005f416300 R09: 1ffff1000be82c76
R10: ffff88007ffd915d R11: 0000000000000001 R12: ffff88005f5dcff8
R13: 00000061d944ea40 R14: ffff88005f407ea0 R15: 1ffff1000be80fc8
 tick_nohz_irq_exit+0xac/0x120 kernel/time/tick-sched.c:1009
 tick_irq_exit kernel/softirq.c:386 [inline]
 irq_exit+0x141/0x1b0 kernel/softirq.c:407
 exiting_irq arch/x86/include/asm/apic.h:652 [inline]
 smp_call_function_interrupt+0x70/0xa0 arch/x86/kernel/smp.c:302
 smp_call_function_single_interrupt+0x9/0x10 include/linux/compiler.h:250
 call_function_single_interrupt+0x9d/0xb0 arch/x86/entry/entry_64.S:722
RIP: 0010:native_safe_halt+0x6/0x10 arch/x86/include/asm/irqflags.h:53
RSP: 0018:ffff88005ee7fdb8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff04
RAX: 0000000000000007 RBX: 1ffff1000bdcffba RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff91672020 RDI: ffff88005ee708f4
RBP: ffff88005ee7fdb8 R08: ffff88005f416060 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff88005ee70040
R13: ffff88005ee7fe70 R14: 0000000000000000 R15: ffff88005ee70040
 </IRQ>
 arch_safe_halt arch/x86/include/asm/paravirt.h:98 [inline]
 default_idle+0x8d/0x600 arch/x86/kernel/process.c:341
 arch_cpu_idle+0xa/0x10 arch/x86/kernel/process.c:332
 default_idle_call+0x4c/0xa0 kernel/sched/idle.c:98
 cpuidle_idle_call kernel/sched/idle.c:156 [inline]
 do_idle+0x287/0x410 kernel/sched/idle.c:245
 cpu_startup_entry+0x18/0x20 kernel/sched/idle.c:350
 start_secondary+0x2d3/0x400 arch/x86/kernel/smpboot.c:275
 secondary_startup_64+0x9f/0x9f arch/x86/kernel/head_64.S:304
Dumping ftrace buffer:
   (ftrace buffer empty)
Kernel Offset: 0xb200000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
Rebooting in 86400 seconds..

-- 

Thanks,
Sasha