| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20170608221336.vem2i3364sljme4n@sasha-lappy>
Date: Thu, 8 Jun 2017 22:13:38 +0000
From: "Levin, Alexander (Sasha Levin)" <alexander.levin@...izon.com>
To: Frederic Weisbecker <fweisbec@...il.com>
CC: Thomas Gleixner <tglx@...utronix.de>,
Ingo Molnar <mingo@...nel.org>,
LKML <linux-kernel@...r.kernel.org>,
Peter Zijlstra <peterz@...radead.org>,
"Rik van Riel" <riel@...hat.com>,
James Hartsock <hartsjc@...hat.com>,
"stable@...r.kernel.org" <stable@...r.kernel.org>,
Tim Wright <tim@...bash.co.uk>, Pavel Machek <pavel@....cz>
Subject: [PATCH] nohz: Fix spurious warning when hrtimer and clockevent get
out of sync
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] <IRQ>
[ 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] </IRQ>
[ 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 : <stack trace>
[ 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 : <stack trace>
[ 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 : <stack trace>
[ 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] <idle>-0 1d.h2 1750485us : hrtimer_cancel: hrtimer=ffff88003dff7aa0
[ 1.430234] <idle>-0 1d.h2 1750490us : <stack trace>
[ 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] <idle>-0 1d.h1 1750495us : hrtimer_expire_entry: hrtimer=ffff88003dff7aa0 function=hrtimer_wakeup now=385000000
[ 1.430234] <idle>-0 1d.h1 1750498us : <stack trace>
[ 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 : <stack trace>
[ 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 : <stack trace>
[ 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] <idle>-0 1d.h2 2720410us : hrtimer_cancel: hrtimer=ffffffffa3374970
[ 1.430234] <idle>-0 1d.h2 2720422us : <stack trace>
[ 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] <idle>-0 1d.h1 2720429us : hrtimer_expire_entry: hrtimer=ffffffffa3374970 function=sched_rt_period_timer now=1157000000
[ 1.430234] <idle>-0 1d.h1 2720433us : <stack trace>
[ 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] <idle>-0 1d.h2 3052672us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1424000000 softexpires=1424000000
[ 1.430234] <idle>-0 1d.h2 3052680us : <stack trace>
[ 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] <idle>-0 1d..2 3052735us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1d..2 3052738us : <stack trace>
[ 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] <idle>-0 1d..2 3052747us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1426000000 softexpires=1426000000
[ 1.430234] <idle>-0 1d..2 3052750us : <stack trace>
[ 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] <idle>-0 1dN.2 3054068us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1dN.2 3054075us : <stack trace>
[ 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] <idle>-0 1dN.2 3054088us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1425000000 softexpires=1425000000
[ 1.430234] <idle>-0 1dN.2 3054091us : <stack trace>
[ 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] <idle>-0 1d..2 3054214us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1d..2 3054217us : <stack trace>
[ 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] <idle>-0 1d..2 3054227us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1428000000 softexpires=1428000000
[ 1.430234] <idle>-0 1d..2 3054229us : <stack trace>
[ 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] <idle>-0 1d.h2 3057833us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1d.h2 3057840us : <stack trace>
[ 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] <idle>-0 1d.h1 3057844us : hrtimer_expire_entry: hrtimer=ffff88003eddcfe0 function=tick_sched_timer now=1428247421
[ 1.430234] <idle>-0 1d.h1 3057846us : <stack trace>
[ 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] <idle>-0 1dN.2 3057926us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1429000000 softexpires=1429000000
[ 1.430234] <idle>-0 1dN.2 3057929us : <stack trace>
[ 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] <idle>-0 1dn.2 3058002us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1dn.2 3058005us : <stack trace>
[ 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] <idle>-0 1dn.2 3058014us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1432000000 softexpires=1432000000
[ 1.430234] <idle>-0 1dn.2 3058017us : <stack trace>
[ 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] <idle>-0 1dN.2 3058031us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1dN.2 3058033us : <stack trace>
[ 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] <idle>-0 1dN.2 3058041us : hrtimer_start: hrtimer=ffff88003eddcfe0 function=tick_sched_timer expires=1429000000 softexpires=1429000000
[ 1.430234] <idle>-0 1dN.2 3058044us : <stack trace>
[ 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] <idle>-0 1d..2 3058105us : hrtimer_cancel: hrtimer=ffff88003eddcfe0
[ 1.430234] <idle>-0 1d..2 3058107us : <stack trace>
[ 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
Powered by blists - more mailing lists