Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751928AbdFHWPU (ORCPT ); Thu, 8 Jun 2017 18:15:20 -0400 Received: from fldsmtpe03.verizon.com ([140.108.26.142]:55405 "EHLO fldsmtpe03.verizon.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751766AbdFHWPQ (ORCPT ); Thu, 8 Jun 2017 18:15:16 -0400 X-IronPort-Anti-Spam-Filtered: false From: "Levin, Alexander (Sasha Levin)" X-IronPort-AV: E=Sophos;i="5.39,315,1493683200"; d="scan'208";a="216479146" To: Frederic Weisbecker CC: Thomas Gleixner , Ingo Molnar , LKML , Peter Zijlstra , "Rik van Riel" , James Hartsock , "stable@vger.kernel.org" , Tim Wright , Pavel Machek Subject: [PATCH] nohz: Fix spurious warning when hrtimer and clockevent get out of sync Thread-Topic: [PATCH] nohz: Fix spurious warning when hrtimer and clockevent get out of sync Thread-Index: AQHS4KR6u0qok5D6cEuc7msinvDApQ== Date: Thu, 8 Jun 2017 22:13:38 +0000 Message-ID: <20170608221336.vem2i3364sljme4n@sasha-lappy> References: <1492783255-5051-1-git-send-email-fweisbec@gmail.com> <1492783255-5051-3-git-send-email-fweisbec@gmail.com> <20170603080638.7okm4ztp7zuphc4b@sasha-lappy> <20170603124237.GA25077@lerouge> <20170603125259.scyapxq2fftqiiz3@sasha-lappy> <20170606145227.GB22016@lerouge> <20170607040801.4r7iqfzynf3d3xom@sasha-lappy> <20170607141400.GA29571@lerouge> <20170607213349.wtc2xhljlx5zjv5f@sasha-lappy> <20170608190702.GB27757@lerouge> In-Reply-To: <20170608190702.GB27757@lerouge> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: user-agent: NeoMutt/20170113 (1.7.2) x-ms-exchange-messagesentrepresentingtype: 1 x-ms-exchange-transport-fromentityheader: Hosted x-originating-ip: [10.144.60.250] Content-Type: text/plain; charset="us-ascii" Content-ID: <8A0F9E54A5D6EF4EB0E8773EB596608D@vzwcorp.com> MIME-Version: 1.0 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Transfer-Encoding: 8bit X-MIME-Autoconverted: from quoted-printable to 8bit by mail.home.local id v58MFOeN003018 Content-Length: 16972 Lines: 364 On Thu, Jun 08, 2017 at 09:07:05PM +0200, Frederic Weisbecker wrote: > Awesome, these traces have been very helpful! So now I think I get what's going on. > Can you please test the following fix? With the patch, I hit the warning early on boot: [ 1.423727] clocksource: Switched to clocksource kvm-clock [ 1.429326] ------------[ cut here ]------------ [ 1.430234] WARNING: CPU: 1 PID: 0 at kernel/time/tick-sched.c:792 __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] Kernel panic - not syncing: panic_on_warn set ... [ 1.430234] [ 1.430234] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.12.0-rc4-next-20170606+ #85 [ 1.430234] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.1-1ubuntu1 04/01/2014 [ 1.430234] Call Trace: [ 1.430234] [ 1.430234] dump_stack+0x100/0x189 [ 1.430234] ? _atomic_dec_and_lock+0x187/0x187 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] panic+0x1dd/0x489 [ 1.430234] ? copy_mm+0x10eb/0x10eb [ 1.430234] ? __probe_kernel_read+0x19c/0x2a0 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] __warn+0x1d3/0x220 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] report_bug+0x1fa/0x2b0 [ 1.430234] do_trap+0x3c4/0x500 [ 1.430234] do_error_trap+0x12f/0x240 [ 1.430234] ? fixup_bad_iret+0x140/0x140 [ 1.430234] ? check_preemption_disabled+0x3b/0x280 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] ? error_entry+0x7c/0xd0 [ 1.430234] ? __this_cpu_preempt_check+0x1c/0x20 [ 1.430234] ? trace_hardirqs_off_caller+0x13e/0x2f0 [ 1.430234] ? trace_hardirqs_off_thunk+0x1a/0x1c [ 1.430234] do_invalid_op+0x1b/0x20 [ 1.430234] invalid_op+0x1e/0x30 [ 1.430234] RIP: 0010:__tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] RSP: 0000:ffff88003ec07e58 EFLAGS: 00010086 [ 1.430234] RAX: 0000000000000000 RBX: ffff88003eddcfe0 RCX: 0000000000000001 [ 1.430234] RDX: 1ffff10007dbba07 RSI: ffffffff9d86f3e0 RDI: ffff88003eddd0b0 [ 1.430234] RBP: ffff88003ec07f38 R08: 0000000000000000 R09: dffffc0000000000 [ 1.430234] R10: 1ffff10007d8325a R11: 0000000000000001 R12: 7fffffffffffffff [ 1.430234] R13: 7fffffffffffffff R14: ffff88003eddd038 R15: ffff88003eddd044 [ 1.430234] ? __tick_nohz_idle_enter+0xe1c/0x15c0 [ 1.430234] ? get_cpu_iowait_time_us+0x2c0/0x2c0 [ 1.430234] ? check_preemption_disabled+0x3b/0x280 [ 1.430234] tick_nohz_irq_exit+0xac/0x120 [ 1.430234] irq_exit+0x168/0x1f0 [ 1.430234] scheduler_ipi+0x196/0x7a0 [ 1.430234] smp_reschedule_interrupt+0x66/0x90 [ 1.430234] reschedule_interrupt+0x9d/0xb0 [ 1.430234] RIP: 0010:native_safe_halt+0x6/0x10 [ 1.430234] RSP: 0000:ffff88003df8fe68 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02 [ 1.430234] RAX: 0000000000000007 RBX: ffff88003df7c040 RCX: ffff88003df7c040 [ 1.430234] RDX: 0000000000000000 RSI: ffffffff9d86f3e0 RDI: ffff88003df7c8f4 [ 1.430234] RBP: ffff88003df8fe68 R08: 0000000000000007 R09: 0000000000000000 [ 1.430234] R10: ffff88003df7c8f8 R11: 0000000000000006 R12: ffffed0007bef808 [ 1.430234] R13: 0000000000000000 R14: ffff88003df7c040 R15: dffffc0000000000 [ 1.430234] [ 1.430234] ? trace_hardirqs_on+0xd/0x10 [ 1.430234] default_idle+0x1f/0x420 [ 1.430234] arch_cpu_idle+0xa/0x10 [ 1.430234] default_idle_call+0x3b/0x70 [ 1.430234] do_idle+0x1ff/0x2e0 [ 1.430234] cpu_startup_entry+0x18/0x20 [ 1.430234] start_secondary+0x2af/0x3b0 [ 1.430234] secondary_startup_64+0x9f/0x9f [ 1.430234] Dumping ftrace buffer: [ 1.430234] --------------------------------- [ 1.430234] watchdog-16 1d..1 1498773us : hrtimer_start: hrtimer=ffff88003eddd1a0 function=watchdog_timer_fn expires=4176000000 softexpires=4176000000 [ 1.430234] watchdog-16 1d..1 1498784us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => watchdog_enable [ 1.430234] => smpboot_thread_fn [ 1.430234] => kthread [ 1.430234] => ret_from_fork [ 1.430234] watchdog-16 1d..4 1498828us : hrtimer_start: hrtimer=ffffffffa3374970 function=sched_rt_period_timer expires=1157000000 softexpires=1157000000 [ 1.430234] watchdog-16 1d..4 1498831us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => __enqueue_rt_entity [ 1.430234] => enqueue_rt_entity [ 1.430234] => enqueue_task_rt [ 1.430234] => enqueue_task [ 1.430234] => __sched_setscheduler [ 1.430234] => _sched_setscheduler [ 1.430234] => sched_setscheduler [ 1.430234] => watchdog_enable [ 1.430234] => smpboot_thread_fn [ 1.430234] => kthread [ 1.430234] => ret_from_fork [ 1.430234] kworker/-19 1d..1 1749551us : hrtimer_start: hrtimer=ffff88003dff7aa0 function=hrtimer_wakeup expires=385000000 softexpires=385000000 [ 1.430234] kworker/-19 1d..1 1749559us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => schedule_hrtimeout_range_clock [ 1.430234] => schedule_hrtimeout [ 1.430234] => wait_task_inactive [ 1.430234] => __kthread_bind_mask [ 1.430234] => kthread_bind_mask [ 1.430234] => create_worker [ 1.430234] => worker_thread [ 1.430234] => kthread [ 1.430234] => ret_from_fork [ 1.430234] -0 1d.h2 1750485us : hrtimer_cancel: hrtimer=ffff88003dff7aa0 [ 1.430234] -0 1d.h2 1750490us : [ 1.430234] => hrtimer_run_queues [ 1.430234] => run_local_timers [ 1.430234] => update_process_times [ 1.430234] => tick_periodic [ 1.430234] => tick_handle_periodic [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d.h1 1750495us : hrtimer_expire_entry: hrtimer=ffff88003dff7aa0 function=hrtimer_wakeup now=385000000 [ 1.430234] -0 1d.h1 1750498us : [ 1.430234] => hrtimer_run_queues [ 1.430234] => run_local_timers [ 1.430234] => update_process_times [ 1.430234] => tick_periodic [ 1.430234] => tick_handle_periodic [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] watchdog-16 1d..1 1821936us : hrtimer_cancel: hrtimer=ffff88003eddd1a0 [ 1.430234] watchdog-16 1d..1 1821946us : [ 1.430234] => hrtimer_cancel [ 1.430234] => watchdog_disable [ 1.430234] => smpboot_thread_fn [ 1.430234] => kthread [ 1.430234] => ret_from_fork [ 1.430234] watchdog-16 1d..1 1840234us : hrtimer_start: hrtimer=ffff88003eddd1a0 function=watchdog_timer_fn expires=4445000000 softexpires=4445000000 [ 1.430234] watchdog-16 1d..1 1840240us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => watchdog_enable [ 1.430234] => smpboot_thread_fn [ 1.430234] => kthread [ 1.430234] => ret_from_fork [ 1.430234] -0 1d.h2 2720410us : hrtimer_cancel: hrtimer=ffffffffa3374970 [ 1.430234] -0 1d.h2 2720422us : [ 1.430234] => hrtimer_run_queues [ 1.430234] => run_local_timers [ 1.430234] => update_process_times [ 1.430234] => tick_periodic [ 1.430234] => tick_handle_periodic [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d.h1 2720429us : hrtimer_expire_entry: hrtimer=ffffffffa3374970 function=sched_rt_period_timer now=1157000000 [ 1.430234] -0 1d.h1 2720433us : [ 1.430234] => hrtimer_run_queues [ 1.430234] => run_local_timers [ 1.430234] => update_process_times [ 1.430234] => tick_periodic [ 1.430234] => tick_handle_periodic [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d.h2 3052672us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1424000000 softexpires=1424000000 [ 1.430234] -0 1d.h2 3052680us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => tick_setup_sched_timer [ 1.430234] => hrtimer_run_queues [ 1.430234] => run_local_timers [ 1.430234] => update_process_times [ 1.430234] => tick_periodic [ 1.430234] => tick_handle_periodic [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d..2 3052735us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1d..2 3052738us : [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_irq_exit [ 1.430234] => irq_exit [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d..2 3052747us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1426000000 softexpires=1426000000 [ 1.430234] -0 1d..2 3052750us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_irq_exit [ 1.430234] => irq_exit [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dN.2 3054068us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1dN.2 3054075us : [ 1.430234] => hrtimer_cancel [ 1.430234] => tick_nohz_restart [ 1.430234] => tick_nohz_idle_exit [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dN.2 3054088us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1425000000 softexpires=1425000000 [ 1.430234] -0 1dN.2 3054091us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => tick_nohz_restart [ 1.430234] => tick_nohz_idle_exit [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d..2 3054214us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1d..2 3054217us : [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_idle_enter [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d..2 3054227us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1428000000 softexpires=1428000000 [ 1.430234] -0 1d..2 3054229us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_idle_enter [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d.h2 3057833us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1d.h2 3057840us : [ 1.430234] => hrtimer_interrupt [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d.h1 3057844us : hrtimer_expire_entry: hrtimer=ffff88003eddcfe0 function=tick_sched_timer now=1428247421 [ 1.430234] -0 1d.h1 3057846us : [ 1.430234] => hrtimer_interrupt [ 1.430234] => local_apic_timer_interrupt [ 1.430234] => smp_apic_timer_interrupt [ 1.430234] => apic_timer_interrupt [ 1.430234] => native_safe_halt [ 1.430234] => default_idle [ 1.430234] => arch_cpu_idle [ 1.430234] => default_idle_call [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dN.2 3057926us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1429000000 softexpires=1429000000 [ 1.430234] -0 1dN.2 3057929us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => tick_nohz_restart [ 1.430234] => tick_nohz_idle_exit [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dn.2 3058002us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1dn.2 3058005us : [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_idle_enter [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dn.2 3058014us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1432000000 softexpires=1432000000 [ 1.430234] -0 1dn.2 3058017us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_idle_enter [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dN.2 3058031us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1dN.2 3058033us : [ 1.430234] => hrtimer_cancel [ 1.430234] => tick_nohz_restart [ 1.430234] => tick_nohz_idle_exit [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1dN.2 3058041us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1429000000 softexpires=1429000000 [ 1.430234] -0 1dN.2 3058044us : [ 1.430234] => hrtimer_start_range_ns [ 1.430234] => tick_nohz_restart [ 1.430234] => tick_nohz_idle_exit [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] -0 1d..2 3058105us : hrtimer_cancel: hrtimer=ffff88003eddcfe0 [ 1.430234] -0 1d..2 3058107us : [ 1.430234] => hrtimer_cancel [ 1.430234] => __tick_nohz_idle_enter [ 1.430234] => tick_nohz_idle_enter [ 1.430234] => do_idle [ 1.430234] => cpu_startup_entry [ 1.430234] => start_secondary [ 1.430234] => verify_cpu [ 1.430234] --------------------------------- -- Thanks, Sasha