#9562 NORM 1.5-F11: 6 second delay when sleeping

[Zarro Boogs per Child]

#9562: 6 second delay when sleeping
------------------------------------+---------------------------------------
           Reporter:  pgf           |       Owner:               
               Type:  defect        |      Status:  new          
           Priority:  normal        |   Milestone:  1.5-F11      
          Component:  not assigned  |     Version:  not specified
         Resolution:                |    Keywords:               
        Next_action:  never set     |    Verified:  0            
Deployment_affected:                |   Blockedby:               
           Blocking:                |  
------------------------------------+---------------------------------------

Old description:

> On a B2 machine, with DCONIRQ ECO, and no wireless card installed (to
> avoid suspend problems with wireless), I usually observe the following
> dmesg sequence when sleeping.  Note the 6 second gap at the bottom.
> Turning on full ACPI debugging gives no further information.
>
> {{{
> [root at localhost ~]# echo mem > /sys/power/state
> [   86.105355] PM: Syncing filesystems ... done.
> [   87.568443] PM: Preparing system for mem sleep
> [   87.573577] Freezing user space processes ... (elapsed 0.00 seconds)
> done.
> [   87.582757] Freezing remaining freezable tasks ... (elapsed 0.00
> seconds) done.
> [   87.590725] PM: Entering mem sleep
> [   87.610264] dcon_source_switch to DCON
> [   88.110104] olpc-dcon: Timeout entering DCON mode; expect a screen
> glitch.
> [   88.117425] olpc-dcon: The DCON has control
> [   88.122059] HDA Intel 0000:00:14.0: PCI INT A disabled
> [   88.140118] ehci_hcd 0000:00:10.4: PCI INT D disabled
> [   88.145547] ehci_hcd 0000:00:10.4: PME# disabled
> [   88.170108] uhci_hcd 0000:00:10.2: PCI INT C disabled
> [   88.175526] uhci_hcd 0000:00:10.2: PME# disabled
> [   88.200120] uhci_hcd 0000:00:10.1: PCI INT B disabled
> [   88.205531] uhci_hcd 0000:00:10.1: PME# disabled
> [   88.230118] uhci_hcd 0000:00:10.0: PCI INT A disabled
> [   88.235535] uhci_hcd 0000:00:10.0: PME# disabled
> [   88.260231] pata_via 0000:00:0f.0: PCI INT A disabled
> [   88.280133] mmc_suspend_host: turning off power on mmc0
> [   88.285708] sdhci_set_ios: power off for mmc0 from b0646688
> [   88.290078] sdhci_set_power: new power value = 0
> [   88.296593] mmc_suspend_host: turning off power on mmc1
> [   88.302176] sdhci_set_ios: power off for mmc1 from b0646688
> [   88.308102] mmc_suspend_host: turning off power on mmc2
> [   88.313685] sdhci_set_ios: power off for mmc2 from b0646688
> [   88.319679] sdhci-pci 0000:00:0c.0: PME# disabled
> [   88.324702] sdhci-pci 0000:00:0c.0: PCI INT A disabled
> [   94.245039] ACPI handle has no context!
> [   94.265027] ACPI: Preparing to enter system sleep state S3
>
> }}}

New description:

 On a B2 machine, with DCONIRQ ECO, and no wireless card installed (to
 avoid suspend problems with wireless), I usually observe the following
 dmesg sequence when sleeping.  Note the 6 second gap at the bottom.
 Turning on full ACPI debugging gives no further information.

 {{{
 [root at localhost ~]# echo mem > /sys/power/state
 [   86.105355] PM: Syncing filesystems ... done.
 [   87.568443] PM: Preparing system for mem sleep
 [   87.573577] Freezing user space processes ... (elapsed 0.00 seconds)
 done.
 [   87.582757] Freezing remaining freezable tasks ... (elapsed 0.00
 seconds) done.
 [   87.590725] PM: Entering mem sleep
 [   87.610264] dcon_source_switch to DCON
 [   88.110104] olpc-dcon: Timeout entering DCON mode; expect a screen
 glitch.
 [   88.117425] olpc-dcon: The DCON has control
 [   88.122059] HDA Intel 0000:00:14.0: PCI INT A disabled
 [   88.140118] ehci_hcd 0000:00:10.4: PCI INT D disabled
 [   88.145547] ehci_hcd 0000:00:10.4: PME# disabled
 [   88.170108] uhci_hcd 0000:00:10.2: PCI INT C disabled
 [   88.175526] uhci_hcd 0000:00:10.2: PME# disabled
 [   88.200120] uhci_hcd 0000:00:10.1: PCI INT B disabled
 [   88.205531] uhci_hcd 0000:00:10.1: PME# disabled
 [   88.230118] uhci_hcd 0000:00:10.0: PCI INT A disabled
 [   88.235535] uhci_hcd 0000:00:10.0: PME# disabled
 [   88.260231] pata_via 0000:00:0f.0: PCI INT A disabled
 [   88.280133] mmc_suspend_host: turning off power on mmc0
 [   88.285708] sdhci_set_ios: power off for mmc0 from b0646688
 [   88.290078] sdhci_set_power: new power value = 0
 [   88.296593] mmc_suspend_host: turning off power on mmc1
 [   88.302176] sdhci_set_ios: power off for mmc1 from b0646688
 [   88.308102] mmc_suspend_host: turning off power on mmc2
 [   88.313685] sdhci_set_ios: power off for mmc2 from b0646688
 [   88.319679] sdhci-pci 0000:00:0c.0: PME# disabled
 [   88.324702] sdhci-pci 0000:00:0c.0: PCI INT A disabled
 [   94.245039] ACPI handle has no context!
 [   94.265027] ACPI: Preparing to enter system sleep state S3

 }}}

--

Comment(by cjb):

 Agreed.  Are you sure it's third and later rather than second and later?

 Given that we're seeing messages about missed IRQs and so on in our resume
 crashes, it seems plausible that we're failing to restore some state at
 resume which is necessary for the resume after that..

-- 
Ticket URL: <http://dev.laptop.org/ticket/9562#comment:2>
One Laptop Per Child <http://laptop.org/>
OLPC bug tracking system