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

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

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

> On 26/08/10 11:09 AM, KOSAKI Motohiro wrote:
> >> If there is anything I can do to debug this problem please let me
> >> know.
> > 
> > Vefa, your above log is very useful. really thanks.
> > So, I'm convinced two things.
> >  - my patch is purely unrelated.
> >  - how to fix your issue.
> > 
> > Can you please try attached patch? I bet this can solve your issue.
> > 
> > Thanks for your patience.
> 
> Hello!
> 
> First of all, thanks a lot for your help - I really appreciate it.
> 
> I applied your new patches on top of your old patches. Hopefully that
> was okay.
> 
> Unfortunately, it didn't work this time. Here's a sample output from the
> new patch.
> 
> === 8< ===
> [58.050208] PM: Preallocating image memory...
> [58.159881] shrink_all_memory start
> [58.232411] PM: shrink memory: pass=1, req:312373 reclaimed:15864 free:358420
> [58.342041] PM: shrink memory: pass=2, req:296509 reclaimed:21837 free:362167
> [60.690035] PM: shrink memory: pass=3, req:274672 reclaimed:25982 free:348006
> [61.754931] PM: shrink memory: pass=4, req:248690 reclaimed:49623 free:371589
> [64.361714] PM: shrink memory: pass=5, req:199067 reclaimed:74683 free:396695
> [64.361769] shrink_all_memory: req:124384 reclaimed:74683 free:396695
> === >8 ===
> 
> The interesting thing is that even though there is a lot of free memory at the
> end, it still hangs. 

Grr. I'm surprised this result ;-)
shrink_all_memory() finish to shrink memory successfully. but your
system still hang immediately after. I have no idea why this mysterious
occur. 

I prepared next debugging patch. It added prenty debug printk. I hope
it enlighten up which path makes system hang-up.

1. apply my new patch

2. Enable following PM debug option in Kconfig

  [*] Power Management support
  [*]   Power Management Debug Support
  [*]     Extra PM attributes in sysfs for low-level debugging/testing
  [*]     Verbose Power Management debugging

3. append following kernel boot option into grub configration file

	no_console_suspend=1

3. kernel build and reboot
4. some prepare
   # echo 8 > /proc/sysrq-trigger
   # cd /sys/power
   # echo 1 > pm_trace
   # echo 0 > pm_async

5. run your test program


> I also included the timestamps; note the one and two second
> delays between the passes.

This is expected result because tmpfs shrink need swap-out. then
we need i/o time.

> 
> Please let me know if there is anything I can do.

Please send me your .config and full dmesg.


Thanks many and many help us!

[-- Attachment #2: 0001-debug-messages.patch --]
[-- Type: application/octet-stream, Size: 2837 bytes --]

From 1b071d7958cb933cf99fbbe565fd33dbdd626a4d Mon Sep 17 00:00:00 2001
From: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
Date: Mon, 15 Feb 2044 10:34:37 +0900
Subject: [PATCH] debug messages

Signed-off-by: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
---
 kernel/power/snapshot.c |   25 +++++++++++++++++++++----
 1 files changed, 21 insertions(+), 4 deletions(-)

diff --git a/kernel/power/snapshot.c b/kernel/power/snapshot.c
index 5e7edfb..c864806 100644
--- a/kernel/power/snapshot.c
+++ b/kernel/power/snapshot.c
@@ -1263,7 +1263,7 @@ int hibernate_preallocate_memory(void)
 	struct timeval start, stop;
 	int error;
 
-	printk(KERN_INFO "PM: Preallocating image memory... ");
+	printk(KERN_INFO "PM: Preallocating image memory... \n");
 	do_gettimeofday(&start);
 
 	error = memory_bm_create(&orig_bm, GFP_IMAGE, PG_ANY);
@@ -1309,6 +1309,7 @@ int hibernate_preallocate_memory(void)
 	 * in memory, allocate page frames for the image and we're done.
 	 */
 	if (size >= saveable) {
+		printk(KERN_INFO "PM: size >= saveable. skip \n");
 		pages = preallocate_image_highmem(save_highmem);
 		pages += preallocate_image_memory(saveable - pages);
 		goto out;
@@ -1335,16 +1336,30 @@ int hibernate_preallocate_memory(void)
 	 * highmem and non-highmem zones separately.
 	 */
 	pages_highmem = preallocate_image_highmem(highmem / 2);
+	printk(KERN_INFO "PM: preallocate_image_highmem %lu %lu\n",
+	       highmem, pages_highmem);
+
 	alloc = (count - max_size) - pages_highmem;
 	pages = preallocate_image_memory(alloc);
-	if (pages < alloc)
+	printk(KERN_INFO "PM: preallocate_image_memory %lu %lu\n",
+	       alloc, pages);
+
+	if (pages < alloc) {
+		printk(KERN_INFO "PM: pages(%lu) < alloc(%lu). error. \n",
+		       pages, alloc);
 		goto err_out;
+	}
 	size = max_size - size;
 	alloc = size;
 	size = preallocate_highmem_fraction(size, highmem, count);
+	printk(KERN_INFO "PM: preallocate_highmem_fraction %lu %lu %lu -> %lu\n",
+	       size, highmem, count, size);
+
 	pages_highmem += size;
 	alloc -= size;
 	pages += preallocate_image_memory(alloc);
+	printk(KERN_INFO "PM: preallocate_image_memory %lu %lu\n",
+	       alloc, pages);
 	pages += pages_highmem;
 
 	/*
@@ -1352,18 +1367,20 @@ int hibernate_preallocate_memory(void)
 	 * pages in memory, but we have allocated more.  Release the excessive
 	 * ones now.
 	 */
+	printk(KERN_INFO "PM: free_unnecessary_pages() \n");
 	free_unnecessary_pages();
 
  out:
 	do_gettimeofday(&stop);
-	printk(KERN_CONT "done (allocated %lu pages)\n", pages);
+	printk(KERN_INFO "done (allocated %lu pages)\n", pages);
 	swsusp_show_speed(&start, &stop, pages, "Allocated");
 
 	return 0;
 
  err_out:
-	printk(KERN_CONT "\n");
+	printk(KERN_INFO "PM: err_out \n");
 	swsusp_free();
+	printk(KERN_INFO "PM: swsusp_free() end \n");
 	return -ENOMEM;
 }
 
-- 
1.6.5.2