Re: 2.6.9-rc2-mm3: swsusp horribly slow on AMD64

Rafael J. Wysocki
2004-09-26T17:04:42Z

On Sunday 26 of September 2004 13:45, Rafael J. Wysocki wrote:
[-- snip --]
> swsusp: Image: 11145 Pages
> swsusp: Pagedir: 0 Pages
> Writing data to swap (11145 pages)... 0%
>
> Here I have to press the red button unless I want to wait for a couple of
> hours. I'll send you more info when there's more.

I figured out that the slowdown occurs in device_resume(), so I put a printk()
in dpm_resume(), like this:

--- drivers/base/power/resume.c 2004-09-26 16:44:09.000000000 +0200
+++ drivers/base/power/resume.c.rjw 2004-09-26 16:43:57.000000000 +0200
@@ -34,6 +34,7 @@
while(!list_empty(&dpm_off)) {
struct list_head * entry = dpm_off.next;
struct device * dev = to_device(entry);
+ printk("%ld\n", jiffies/HZ);
list_del_init(entry);

if (!dev->power.prev_state)

>From it, I have got the following results:

PM: writing image.
4294807
[ ... ]
4294807
PCI: Setting latency timer of device 0000:00:02.0 to 64
4294813
PCI: Setting latency timer of device 0000:00:02.1 to 64
4294817
PCI: Setting latency timer of device 0000:00:02.2 to 64
4294821
ACPI: PCI interrupt 0000:00:06.0[A] -> GSI 5 (level, low) -> IRQ 5
PCI: Setting latency timer of device 0000:00:06.0 to 64
4294822
[ ... ]
4294822
ACPI: PCI interrupt 0000:02:00.0[A] -> GSI 11 (level, low) -> IRQ 11
4294822
4294825
4294828
ACPI: PCI interrupt 0000:02:01.2[C] -> GSI 11 (level, low) -> IRQ 11
4294828
[ ... ]
4294828
4294829
[ ... ]
4294829

As you can see, the difference between the first and the last timestamp is 22.
However, if I make the same change in 2.6.9-rc2-mm1, I get:

PM: writing image.
4294761
[ ... ]
4294761
PCI: Setting latency timer of device 0000:00:02.0 to 64
4294761
PCI: Setting latency timer of device 0000:00:02.1 to 64
4294761
PCI: Setting latency timer of device 0000:00:02.2 to 64
4294761
ACPI: PCI interrupt 0000:00:06.0[A] -> GSI 5 (level, low) -> IRQ 5
PCI: Setting latency timer of device 0000:00:06.0 to 64
4294762
[ ... ]
4294762
ACPI: PCI interrupt 0000:02:00.0[A] -> GSI 11 (level, low) -> IRQ 11
4294762
4294762
4294762
ACPI: PCI interrupt 0000:02:01.2[C] -> GSI 11 (level, low) -> IRQ 11
4294762
[ ... ]
4294762

so the difference between the first and the last timestamp is 1 (ie 22 times
less).

Now, I have no idea about what may be responsible for such a slowdown, but I
suspect that it's related to PCI. I really don't know what to look for, so
if you can give me any hint, please do.

Greets,
RJW

--
- Would you tell me, please, which way I ought to go from here?
- That depends a good deal on where you want to get to.
-- Lewis Carroll "Alice's Adventures in Wonderland"