Re: [Bisected Regression in 2.6.35] A full tmpfs filesystem causes hibernationto hang

[KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>]

[-- Attachment #1: Type: text/plain, Size: 2297 bytes --]

> Hello all,
> 
> I am using Debian Sid on a Toshiba Satellite A100 laptop. After testing
> 2.6.35 for a while, I noticed that sometimes my hibernation attempts
> would fail. I should say that I never had such a problem before 2.6.35.
> The hibernation process hangs with 2.6.35 after printing the following:
> 
> === 8< ===
> ...
> Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
> PM: Preallocating image memory...
> === >8 ===
> 
> After a short investigation, I found out that this only happens when my
> tmpfs filesystem on /tmp had a lot of data in it. When my tmpfs is empty,
> I have no problems.
> 
> So I wrote a short script which fills up the tmpfs on /tmp and tries to
> hibernate, and I bisected the kernel using this script.
> 
> The end result is that the following commit causes this regression:
> 
> === 8< ===
> commit bb21c7ce18eff8e6e7877ca1d06c6db719376e3c
> Author: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
> Date:   Fri Jun 4 14:15:05 2010 -0700
> 
>     vmscan: fix do_try_to_free_pages() return value when priority==0 reclaim failure
> 
>     ...
> === >8 ===
> 
> I have run 2.6.35-rc6, 2.6.35 and 2.6.35.1 with this commit reverted,
> and I am happy to say that I haven't experienced any problems for at
> least 17 days.
> 
> It looks like this change was included with 2.6.35-rc1. I am sorry
> for not testing earlier.
> 
> I am willing to do testing in case anyone would like me to try patches.
> 
> Regards,
> 
> M. Vefa Bicakci

Hmm... 
I've tested hibernation case for a while. but I have no luck. I couldn't
reproduce your issue. Very sorry. Can you please help our debugging? 
If possible, I hope to run following three test.

1. Please let me know your machine & test script

% cat /proc/meminfo
% cat /proc/vmstat
% cat /proc/zoneinfo
% df
% cat your-fills-up-the-tmpfs-script

2. call shrink_all_memory() forcely and show result

% cat /proc/meminfo
% cat /proc/zoneinfo
# echo 1 > /proc/sys/vm/shrink_all_memory
# tail /var/log/messages
% cat /proc/meminfo
% cat /proc/zoneinfo


3. reset zone_reclaim_stat and rerun shrink_all_memory

# echo 1 > /proc/sys/vm/reset_reclaim_stat
% cat /proc/meminfo
% cat /proc/zoneinfo
# echo 1 > /proc/sys/vm/shrink_all_memory
# tail /var/log/messages
% cat /proc/meminfo
% cat /proc/zoneinfo



[-- Attachment #2: 0001-debug-print-sysctl.patch --]
[-- Type: application/octet-stream, Size: 2174 bytes --]

From 57544e31e5ad966a86f7ff9dbe9299877b2fb9c8 Mon Sep 17 00:00:00 2001
From: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
Date: Fri, 20 Aug 2010 11:08:33 +0900
Subject: [PATCH 1/4] debug print + sysctl

Signed-off-by: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
---
 kernel/sysctl.c |   20 ++++++++++++++++++++
 mm/vmscan.c     |    7 +++++++
 2 files changed, 27 insertions(+), 0 deletions(-)

diff --git a/kernel/sysctl.c b/kernel/sysctl.c
index d24f761..e1b22ed 100644
--- a/kernel/sysctl.c
+++ b/kernel/sysctl.c
@@ -961,6 +961,19 @@ static struct ctl_table kern_table[] = {
 	{ }
 };
 
+static int sysctl_shrink_all_memory;
+static int shrink_all_memory_handler(ctl_table *table, int write,
+				     void __user *buffer, size_t *length,
+				     loff_t *ppos)
+{
+	proc_dointvec_minmax(table, write, buffer, length, ppos);
+	if (write) {
+		shrink_all_memory(sysctl_shrink_all_memory);
+	}
+	return 0;
+}
+
+
 static struct ctl_table vm_table[] = {
 	{
 		.procname	= "overcommit_memory",
@@ -1318,6 +1331,13 @@ static struct ctl_table vm_table[] = {
 		.extra2		= &one,
 	},
 #endif
+	{
+		.procname	= "shrink_all_memory",
+		.data		= &sysctl_shrink_all_memory,
+		.maxlen		= sizeof(sysctl_shrink_all_memory),
+		.mode		= 0644,
+		.proc_handler	= shrink_all_memory_handler,
+	},
 
 /*
  * NOTE: do not add new entries to this table unless you have read
diff --git a/mm/vmscan.c b/mm/vmscan.c
index b94fe1b..1ce6c43 100644
--- a/mm/vmscan.c
+++ b/mm/vmscan.c
@@ -2410,6 +2410,8 @@ unsigned long shrink_all_memory(unsigned long nr_to_reclaim)
 	struct task_struct *p = current;
 	unsigned long nr_reclaimed;
 
+	printk(KERN_ERR "shrink_all_memory start\n");
+
 	p->flags |= PF_MEMALLOC;
 	lockdep_set_current_reclaim_state(sc.gfp_mask);
 	reclaim_state.reclaimed_slab = 0;
@@ -2421,6 +2423,11 @@ unsigned long shrink_all_memory(unsigned long nr_to_reclaim)
 	lockdep_clear_current_reclaim_state();
 	p->flags &= ~PF_MEMALLOC;
 
+	printk(KERN_ERR "shrink_all_memory: req:%ld reclaimed:%ld free:%ld\n",
+	       nr_to_reclaim,
+		nr_reclaimed,
+	       global_page_state(NR_FREE_PAGES));
+
 	return nr_reclaimed;
 }
 #endif /* CONFIG_HIBERNATION */
-- 
1.6.5.2


[-- Attachment #3: 0003-debug-reset_reclaim_stat.patch --]
[-- Type: application/octet-stream, Size: 1654 bytes --]

From 9b5776352f8d46e3ada80f91f9d978870105630f Mon Sep 17 00:00:00 2001
From: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
Date: Fri, 20 Aug 2010 15:28:22 +0900
Subject: [PATCH 3/4] debug: reset_reclaim_stat

Signed-off-by: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
---
 kernel/sysctl.c |   31 +++++++++++++++++++++++++++++++
 1 files changed, 31 insertions(+), 0 deletions(-)

diff --git a/kernel/sysctl.c b/kernel/sysctl.c
index e1b22ed..3b72836 100644
--- a/kernel/sysctl.c
+++ b/kernel/sysctl.c
@@ -973,6 +973,30 @@ static int shrink_all_memory_handler(ctl_table *table, int write,
 	return 0;
 }
 
+#include <linux/mm_types.h>
+#include <linux/mmzone.h>
+
+static int reset_reclaim_stat_handler(ctl_table *table, int write,
+				      void __user *buffer, size_t *length,
+				      loff_t *ppos)
+{
+	struct zone *zone;
+	struct zone_reclaim_stat *rstat;
+
+	if (write) {
+		for_each_populated_zone(zone) {
+			spin_lock_irq(&zone->lru_lock);
+			rstat = &zone->reclaim_stat;
+			rstat->recent_scanned[0] = 0;
+			rstat->recent_rotated[0] = 0;
+			rstat->recent_scanned[1] = 0;
+			rstat->recent_rotated[1] = 0;
+			spin_unlock_irq(&zone->lru_lock);
+		}
+
+	}
+	return 0;
+}
 
 static struct ctl_table vm_table[] = {
 	{
@@ -1338,6 +1362,13 @@ static struct ctl_table vm_table[] = {
 		.mode		= 0644,
 		.proc_handler	= shrink_all_memory_handler,
 	},
+	{
+		.procname	= "reset_reclaim_stat",
+		.data		= &sysctl_shrink_all_memory,
+		.maxlen		= sizeof(sysctl_shrink_all_memory),
+		.mode		= 0644,
+		.proc_handler	= reset_reclaim_stat_handler,
+	},
 
 /*
  * NOTE: do not add new entries to this table unless you have read
-- 
1.6.5.2


[-- Attachment #4: 0004-debug-zone_info-reclaim_stat.patch --]
[-- Type: application/octet-stream, Size: 1575 bytes --]

From 87ce7b4a24f3b381a204ebd654050ac2c6bc2d14 Mon Sep 17 00:00:00 2001
From: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
Date: Fri, 20 Aug 2010 15:52:47 +0900
Subject: [PATCH 4/4] debug: zone_info reclaim_stat

Signed-off-by: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
---
 mm/vmstat.c |   27 +++++++++++++++++++++++++++
 1 files changed, 27 insertions(+), 0 deletions(-)

diff --git a/mm/vmstat.c b/mm/vmstat.c
index 7759941..bee3ba3 100644
--- a/mm/vmstat.c
+++ b/mm/vmstat.c
@@ -860,6 +860,33 @@ static void zoneinfo_show_print(struct seq_file *m, pg_data_t *pgdat,
 		   zone->prev_priority,
 		   zone->zone_start_pfn,
 		   zone->inactive_ratio);
+
+	{
+		extern int vm_swappiness;
+		int anon_prio = vm_swappiness;
+		int file_prio = 200 - vm_swappiness;
+		unsigned long ap;
+		unsigned long fp;
+		struct zone_reclaim_stat *reclaim_stat = &zone->reclaim_stat;
+
+		ap = (anon_prio + 1) * (reclaim_stat->recent_scanned[0] + 1);
+		ap /= reclaim_stat->recent_rotated[0] + 1;
+		fp = (file_prio + 1) * (reclaim_stat->recent_scanned[1] + 1);
+		fp /= reclaim_stat->recent_rotated[1] + 1;
+
+		seq_printf(m,
+			   "\n recent_anon_rotated: %lu"
+			   "\n recent_anon_scanned: %lu"
+			   "\n recent_file_rotated: %lu"
+			   "\n recent_file_scanned: %lu"
+			   "\n anon_ratio:          %lu"
+			   ,
+			   zone->reclaim_stat.recent_rotated[0],
+			   zone->reclaim_stat.recent_scanned[0],
+			   zone->reclaim_stat.recent_rotated[1],
+			   zone->reclaim_stat.recent_scanned[1],
+			   (ap * 100) / (ap + fp +1));
+	}
 	seq_putc(m, '\n');
 }
 
-- 
1.6.5.2