Messages in this thread | | | Subject | Re: [PATCH v2] watchdog: Fix possible soft lockup warning at bootup | From | Waiman Long <> | Date | Thu, 16 Jan 2020 10:34:20 -0500 |
| |
On 1/16/20 6:44 AM, Thomas Gleixner wrote: > Thomas Gleixner <tglx@linutronix.de> writes: > > Added ARM64 and ThunderX folks > >> Waiman Long <longman@redhat.com> writes: >>> By adding some instrumentation code, it was found that for cpu 14, >>> watchdog_enable() was called early with a timestamp of 1. That activates >>> the watchdog time checking logic. It was also found that the monotonic >>> time measured during the smp_init() phase runs much slower than the >>> real elapsed time as shown by the below debug printf output: >>> >>> [ 1.138522] run_queues, watchdog_timer_fn: now = 170000000 >>> [ 25.519391] run_queues, watchdog_timer_fn: now = 4170000000 >>> >>> In this particular case, it took about 24.4s of elapsed time for the >>> clock to advance 4s which is the soft expiration time that is required >>> to trigger the calling of watchdog_timer_fn(). That clock slowdown >>> stopped once the smp_init() call was done and the clock time ran at >>> the same rate as the elapsed time afterward. > And looking at this with a more awake brain, the root cause is pretty > obvious. > > sched_clock() advances by 24 seconds, but clock MONOTONIC on which the > watchdog timer is based does not. As the timestamps you printed have 7 > trailing zeros, it's pretty clear that timekeeping is still jiffies > based at this point and HZ is set to 100. > > So while bringing up the non-boot CPUs the boot CPU loses ~2000 timer > interrupts. That needs to be fixed and not papered over. > You are right that the root-causing effort wasn't complete and I took the easy way out. As I have limited knowledge on how the timer code work, I was not sure how to start further investigation at that time. Your insight gives me a hint on where to start now. So I will dig further in to see what causes this.
Thanks, Longman
| |