Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   Shile Zhang <shile.zhang@linux.alibaba.com>
To:     Andrew Morton <akpm@linux-foundation.org>,
        Pavel Tatashin <pasha.tatashin@oracle.com>
Cc:     linux-mm@kvack.org, linux-kernel@vger.kernel.org,
        Shile Zhang <shile.zhang@linux.alibaba.com>
Subject: [PATCH 0/1] try to fix tick_sched timer stuck issue
Date:   Fri, 10 Jan 2020 16:25:09 +0800
Message-Id: <20200110082510.172517-1-shile.zhang@linux.alibaba.com>
MIME-Version: 1.0
Content-Transfer-Encoding: 8bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

Hi Andrew and Pavel,

I found the 'tick_sched timer stuck' issue when enabled deferred pages
initialize feature on my 2c320g VM.
The dmesg log shown that deferred 81,699,533 pages (about 310GB) only
with 1ms!

    [    0.340130] node 0 initialised, 81699533 pages in 1ms

Obviously that is wrong time, and the timestamp in dmesg log. I checked
the sysytemd-analyze, also is wrong time:

    Startup finished in 837ms (kernel) + 1.026s (initrd) + 1.542s (userspace) = 3.407s

In fact, to initialize 320GB memory needs about 2+s on my VM.

I guess it possible caused by the timer is blocked during memory
initialising, so I added debug log based on my roughly anaylsis,
inside 'pgdat_resize_{lock,unlock}', as following:
---8<---
diff --git a/include/linux/memory_hotplug.h b/include/linux/memory_hotplug.h
index 92b1047..7c00c56 100644
--- a/include/linux/memory_hotplug.h
+++ b/include/linux/memory_hotplug.h
@@ -285,13 +285,13 @@ static inline bool movable_node_is_enabled(void)
 void pgdat_resize_lock(struct pglist_data *pgdat, unsigned long *flags)
 {
        spin_lock_irqsave(&pgdat->node_size_lock, *flags);
-       trace_printk("DBG: pgdat_resize_lock: jiffies=%lu\n", jiffies);
+       trace_printk("  DBG: jiffies=%lu after pgdat_resize_lock\n", jiffies);
 }
 static inline
 void pgdat_resize_unlock(struct pglist_data *pgdat, unsigned long *flags)
 {
        mdelay(100);
-       trace_printk("DBG: pgdat_resize_unlock: jiffies=%lu\n", jiffies);
+       trace_printk("DBG: jiffies=%lu before pgdat_resize_unlock\n", jiffies);
        spin_unlock_irqrestore(&pgdat->node_size_lock, *flags);
 }
 static inline
--->8---

Note, I add 'mdelay(100)' to check if the jiffies is stuck to update.
The trace shown that the jiffies was stuck inside pgdat_resize_{lock,unlock}:

    pgdatinit0-19    [000] d...     0.339850: pgdat_resize_lock:   DBG: jiffies=4294667301 after pgdat_resize_lock
    pgdatinit0-19    [000] d...     2.929611: pgdat_resize_unlock: DBG: jiffies=4294667301 before pgdat_resize_unlock

I think the root cause is clear now.

I'm not clear about the original 'window issue' mentioned by Pavel,
in commit:
https://lore.kernel.org/patchwork/patch/933504/

I just try to fix this timer issue, please help to review if it is OK to
fix it, or give some advise to fix this issue gracefully, thanks!

One more question is, I found there also other spin_lock_irqsave be used in
the kernel boot path on boot CPU, but I cannot search any issue reported
about if interrupts can be disabled on boot CPU on boot path. How we ensure
the tick_sched timer be fired in time? :r the accuracy of system wall clock?

Thanks!

Shile Zhang (1):
  mm: fix tick_sched timer blocked by pgdat_resize_lock

 include/linux/memory_hotplug.h | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)

-- 
2.24.0.rc2