[Bug 22907] Suspend to ram almost works but has hda timeouts issues

Dan dan at digitaldan.com
Wed Apr 19 18:04:46 UTC 2006


Public bug reported:

Affects: linux-source-2.6.15 acpi-support (Ubuntu)
       Severity: Normal
       Priority: Medium
     Assignee: Matthew Garrett
         Status: Confirmed


Description:
This is on a new Sony VGN-t350p laptop.  I have enabled suspend to ram in
acpi-support and am passing acpi_sleep=s3_bios on boot to the kernel.  The
laptop goes to sleep correctly, but when it wakes up I'm getting hda timeout
errors in the system log, these take 60 or 120 seconds to reset.  Everything
else works though when the drives return. I have tried using the disable dma
option in the acpi-support file , but with no luck.  s3 sleep is so close!!!

Sep 30 11:09:46 localhost dhclient: There is already a pid file
/var/run/dhclient.eth1.pid with pid 6475
Sep 30 11:09:46 localhost dhclient: killed old client process, removed PID file
Sep 30 11:09:46 localhost dhclient: Internet Systems Consortium DHCP Client V3.0.2
Sep 30 11:09:46 localhost dhclient: Copyright 2004 Internet Systems Consortium.
Sep 30 11:09:46 localhost dhclient: All rights reserved.
Sep 30 11:09:46 localhost dhclient: For info, please visit
http://www.isc.org/products/DHCP
Sep 30 11:09:46 localhost dhclient:
Sep 30 11:09:46 localhost dhclient: sit0: unknown hardware address type 776
Sep 30 11:09:46 localhost dhclient: sit0: unknown hardware address type 776
Sep 30 11:09:46 localhost dhclient: Listening on LPF/eth1/00:13:ce:10:b6:35
Sep 30 11:09:46 localhost dhclient: Sending on   LPF/eth1/00:13:ce:10:b6:35
Sep 30 11:09:46 localhost dhclient: Sending on   Socket/fallback
Sep 30 11:09:46 localhost dhclient: DHCPRELEASE on eth1 to 192.168.1.6 port 67
Sep 30 11:09:46 localhost dhclient: receive_packet failed on eth1: Network is down
Sep 30 11:09:46 localhost kernel: [4295429.347000] bridge-eth1: disabling the bridge
Sep 30 11:09:46 localhost kernel: [4295429.351000] bridge-eth1: down
Sep 30 11:09:46 localhost kernel: [4295429.528000] ACPI: PCI interrupt for
device 0000:02:0b.0 disabled
Sep 30 11:09:46 localhost kernel: [4295429.544000] uhci_hcd 0000:00:1d.0:
remove, state 1
Sep 30 11:09:46 localhost kernel: [4295429.544000] usb usb1: USB disconnect,
address 1
Sep 30 11:09:47 localhost kernel: [4295429.703000] uhci_hcd 0000:00:1d.0: USB
bus 1 deregistered
Sep 30 11:09:47 localhost kernel: [4295429.706000] ACPI: PCI interrupt for
device 0000:00:1d.0 disabled
Sep 30 11:09:47 localhost kernel: [4295429.706000] uhci_hcd 0000:00:1d.1:
remove, state 1
Sep 30 11:09:47 localhost kernel: [4295429.706000] usb usb2: USB disconnect,
address 1
Sep 30 11:09:47 localhost kernel: [4295429.874000] uhci_hcd 0000:00:1d.1: USB
bus 2 deregistered
Sep 30 11:09:47 localhost kernel: [4295429.876000] ACPI: PCI interrupt for
device 0000:00:1d.1 disabled
Sep 30 11:09:47 localhost kernel: [4295429.876000] uhci_hcd 0000:00:1d.2:
remove, state 1
Sep 30 11:09:47 localhost kernel: [4295429.876000] usb usb3: USB disconnect,
address 1
Sep 30 11:09:47 localhost kernel: [4295429.876000] usb 3-1: USB disconnect,
address 2
Sep 30 11:09:47 localhost hcid[7567]: HCI dev 0 down
Sep 30 11:09:47 localhost hcid[7567]: Stoping security manager 0
Sep 30 11:09:47 localhost hcid[7567]: HCI dev 0 unregistered
Sep 30 11:09:47 localhost kernel: [4295430.213000] uhci_hcd 0000:00:1d.2: USB
bus 3 deregistered
Sep 30 11:09:47 localhost kernel: [4295430.218000] ACPI: PCI interrupt for
device 0000:00:1d.2 disabled
Sep 30 11:09:47 localhost kernel: [4295430.235000] ehci_hcd 0000:00:1d.7:
remove, state 1
Sep 30 11:09:47 localhost kernel: [4295430.235000] usb usb4: USB disconnect,
address 1
Sep 30 11:09:47 localhost kernel: [4295430.388000] ehci_hcd 0000:00:1d.7: USB
bus 4 deregistered
Sep 30 11:09:47 localhost kernel: [4295430.424000] ACPI: PCI interrupt for
device 0000:00:1d.7 disabled
Sep 30 11:10:32 localhost kernel: [4295431.254000] Stopping tasks:
===============================================================================|
Sep 30 11:10:32 localhost kernel: [4295431.260000] GTM info
78,3c,ffffffff,ffffffff,3
Sep 30 11:10:32 localhost kernel: [4295431.262000] GTM info
78,14,ffffffff,ffffffff,3
Sep 30 11:10:32 localhost kernel: [4295431.909000] ACPI: PCI interrupt for
device 0000:02:08.0 disabled
Sep 30 11:10:32 localhost kernel: [4295431.920000] ACPI: PCI interrupt for
device 0000:02:04.0 disabled
Sep 30 11:10:32 localhost kernel: [4295431.920000] ACPI: PCI interrupt for
device 0000:00:1f.5 disabled
Sep 30 11:10:32 localhost kernel: [4295431.920000] Back to C!
Sep 30 11:10:32 localhost kernel: [4295445.063000]     ACPI-0299: *** Error: No
installed handler for fixed event [00000002]
Sep 30 11:10:32 localhost kernel: [4295445.072000] ACPI: PCI Interrupt
0000:00:02.0[A] -> Link [LNKA] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:10:32 localhost kernel: [4295445.072000] ACPI: PCI Interrupt
0000:00:1f.1[A]: no GSI
Sep 30 11:10:32 localhost kernel: [4295445.072000] ACPI: PCI Interrupt
0000:00:1f.5[B] -> Link [LNKB] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:35 localhost kernel: [4295445.072000] PCI: Setting latency timer of
device 0000:00:1f.5 to 64
Sep 30 11:11:35 localhost kernel: [4295445.333000] ACPI: PCI Interrupt
0000:02:04.0[A] -> Link [LNKE] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:35 localhost kernel: [4295445.333000] PCI: Enabling device
0000:02:04.2 (0000 -> 0002)
Sep 30 11:11:35 localhost kernel: [4295445.333000] ACPI: PCI Interrupt
0000:02:04.2[C] -> Link [LNKG] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:35 localhost kernel: [4295445.674000] Start STM
Sep 30 11:11:35 localhost kernel: [4295445.675000] start GTF
Sep 30 11:11:35 localhost kernel: [4295445.675000] data 3,1,0,0,0,a0,ef
Sep 30 11:11:35 localhost kernel: [4295445.675000] data 3,41,0,0,0,a0,ef
Sep 30 11:11:35 localhost kernel: [4295475.677000] hda: lost interrupt
Sep 30 11:11:35 localhost kernel: [4295475.677000] Start STM
Sep 30 11:11:35 localhost kernel: [4295475.678000] start GTF
Sep 30 11:11:35 localhost hal.hotplug[8462]: DEVPATH is not set (subsystem input)
Sep 30 11:11:35 localhost hal.hotplug[8447]: DEVPATH is not set (subsystem input)
Sep 30 11:11:35 localhost kernel: [4295475.678000] data 3,1,0,0,0,a0,ef
Sep 30 11:11:35 localhost kernel: [4295475.678000] data 3,42,0,0,0,a0,ef
Sep 30 11:11:35 localhost kernel: [4295475.681000] Restarting tasks... done
Sep 30 11:11:35 localhost kernel: [4295495.677000] hda: dma_timer_expiry: dma
status == 0x21
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: DMA timeout error
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: dma timeout error:
status=0x50 { DriveReady SeekComplete }
Sep 30 11:11:35 localhost kernel: [4295505.677000]
Sep 30 11:11:35 localhost kernel: [4295505.677000] ide: failed opcode was: unknown
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: status error:
status=0x50 { DriveReady SeekComplete }
Sep 30 11:11:35 localhost kernel: [4295505.677000]
Sep 30 11:11:35 localhost kernel: [4295505.677000] ide: failed opcode was: unknown
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: no DRQ after issuing
MULTWRITE_EXT
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: status error:
status=0x50 { DriveReady SeekComplete }
Sep 30 11:11:35 localhost kernel: [4295505.677000]
Sep 30 11:11:35 localhost kernel: [4295505.677000] ide: failed opcode was: unknown
Sep 30 11:11:35 localhost kernel: [4295505.677000] hda: no DRQ after issuing
MULTWRITE_EXT
Sep 30 11:11:35 localhost kernel: [4295535.677000] hda: lost interrupt
Sep 30 11:11:35 localhost kernel: [4295535.677000] hda: status error:
status=0x50 { DriveReady SeekComplete }
Sep 30 11:11:35 localhost kernel: [4295535.677000]
Sep 30 11:11:35 localhost kernel: [4295535.677000] ide: failed opcode was: unknown
Sep 30 11:11:35 localhost kernel: [4295535.677000] hda: no DRQ after issuing
MULTWRITE_EXT
Sep 30 11:11:35 localhost kernel: [4295535.677000] hda: status error:
status=0x50 { DriveReady SeekComplete }
Sep 30 11:11:35 localhost kernel: [4295535.677000]
Sep 30 11:11:35 localhost kernel: [4295535.677000] ide: failed opcode was: unknown
Sep 30 11:11:35 localhost kernel: [4295535.677000] hda: no DRQ after issuing
MULTWRITE_EXT
Sep 30 11:11:35 localhost kernel: [4295535.727000] ide0: reset: success
Sep 30 11:11:35 localhost kernel: [4295538.282000] alps.c: Enabling hardware tapping
Sep 30 11:11:35 localhost kernel: [4295538.436000] input: PS/2 Mouse on
isa0060/serio1
Sep 30 11:11:35 localhost kernel: [4295538.463000] input: AlpsPS/2 ALPS
GlidePoint on isa0060/serio1
Sep 30 11:11:35 localhost hal.hotplug[8537]: DEVPATH is not set (subsystem input)
Sep 30 11:11:35 localhost input.agent[8538]:      tsdev: already loaded
Sep 30 11:11:35 localhost input.agent[8538]:      mousedev: already loaded
Sep 30 11:11:35 localhost input.agent[8538]:      evdev: already loaded
Sep 30 11:11:35 localhost hal.hotplug[8611]: DEVPATH is not set (subsystem input)
Sep 30 11:11:36 localhost input.agent[8612]:      tsdev: already loaded
Sep 30 11:11:36 localhost input.agent[8642]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8534]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8509]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8524]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8548]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8612]:      mousedev: already loaded
Sep 30 11:11:36 localhost input.agent[8612]:      joydev: already loaded
Sep 30 11:11:36 localhost kernel: [4295539.769000] ipw2200: Intel(R)
PRO/Wireless 2200/2915 Network Driver, 1.0.6
Sep 30 11:11:36 localhost kernel: [4295539.769000] ipw2200: Copyright(c)
2003-2004 Intel Corporation
Sep 30 11:11:36 localhost kernel: [4295539.778000] ACPI: PCI Interrupt
0000:02:0b.0[A] -> Link [LNKD] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:36 localhost kernel: [4295539.778000] ipw2200: Detected Intel
PRO/Wireless 2200BG Network Connection
Sep 30 11:11:36 localhost input.agent[8612]:      evdev: already loaded
Sep 30 11:11:36 localhost input.agent[8677]:      evdev: already loaded
Sep 30 11:11:37 localhost kernel: [4295540.106000] USB Universal Host Controller
Interface driver v2.2
Sep 30 11:11:37 localhost kernel: [4295540.107000] ACPI: PCI Interrupt
0000:00:1d.0[A] -> Link [LNKA] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:37 localhost kernel: [4295540.107000] PCI: Setting latency timer of
device 0000:00:1d.0 to 64
Sep 30 11:11:37 localhost kernel: [4295540.107000] uhci_hcd 0000:00:1d.0: Intel
Corporation 82801DB/DBL/DBM (ICH4/ICH4-L/ICH4-M) USB UHCI Controller #1
Sep 30 11:11:37 localhost kernel: [4295540.175000] uhci_hcd 0000:00:1d.0: new
USB bus registered, assigned bus number 1
Sep 30 11:11:37 localhost kernel: [4295540.175000] uhci_hcd 0000:00:1d.0: irq 9,
io base 0x00001820
Sep 30 11:11:37 localhost kernel: [4295540.178000] hub 1-0:1.0: USB hub found
Sep 30 11:11:37 localhost kernel: [4295540.178000] hub 1-0:1.0: 2 ports detected
Sep 30 11:11:37 localhost kernel: [4295540.181000] ACPI: PCI Interrupt
0000:00:1d.1[B] -> Link [LNKD] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:37 localhost kernel: [4295540.181000] PCI: Setting latency timer of
device 0000:00:1d.1 to 64
Sep 30 11:11:37 localhost kernel: [4295540.181000] uhci_hcd 0000:00:1d.1: Intel
Corporation 82801DB/DBL/DBM (ICH4/ICH4-L/ICH4-M) USB UHCI Controller #2
Sep 30 11:11:37 localhost kernel: [4295540.243000] uhci_hcd 0000:00:1d.1: new
USB bus registered, assigned bus number 2
Sep 30 11:11:37 localhost kernel: [4295540.243000] uhci_hcd 0000:00:1d.1: irq 9,
io base 0x00001840
Sep 30 11:11:37 localhost kernel: [4295540.245000] hub 2-0:1.0: USB hub found
Sep 30 11:11:37 localhost kernel: [4295540.245000] hub 2-0:1.0: 2 ports detected
Sep 30 11:11:37 localhost kernel: [4295540.248000] ACPI: PCI Interrupt
0000:00:1d.2[C] -> Link [LNKC] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:37 localhost kernel: [4295540.248000] PCI: Setting latency timer of
device 0000:00:1d.2 to 64
Sep 30 11:11:37 localhost kernel: [4295540.248000] uhci_hcd 0000:00:1d.2: Intel
Corporation 82801DB/DBL/DBM (ICH4/ICH4-L/ICH4-M) USB UHCI Controller #3
Sep 30 11:11:37 localhost kernel: [4295540.310000] uhci_hcd 0000:00:1d.2: new
USB bus registered, assigned bus number 3
Sep 30 11:11:37 localhost kernel: [4295540.310000] uhci_hcd 0000:00:1d.2: irq 9,
io base 0x00001860
Sep 30 11:11:37 localhost kernel: [4295540.312000] hub 3-0:1.0: USB hub found
Sep 30 11:11:37 localhost kernel: [4295540.312000] hub 3-0:1.0: 2 ports detected
Sep 30 11:11:37 localhost kernel: [4295540.348000] ACPI: PCI Interrupt
0000:00:1d.7[D] -> Link [LNKH] -> GSI 9 (level, low) -> IRQ 9
Sep 30 11:11:37 localhost kernel: [4295540.348000] PCI: Setting latency timer of
device 0000:00:1d.7 to 64
Sep 30 11:11:37 localhost kernel: [4295540.348000] ehci_hcd 0000:00:1d.7: Intel
Corporation 82801DB/DBM (ICH4/ICH4-M) USB2 EHCI Controller
Sep 30 11:11:37 localhost kernel: [4295540.348000] ehci_hcd 0000:00:1d.7: debug
port 1
Sep 30 11:11:37 localhost kernel: [4295540.350000] ehci_hcd 0000:00:1d.7: new
USB bus registered, assigned bus number 4
Sep 30 11:11:37 localhost kernel: [4295540.350000] ehci_hcd 0000:00:1d.7: irq 9,
io mem 0xe0100000
Sep 30 11:11:37 localhost kernel: [4295540.354000] PCI: cache line size of 32 is
not supported by device 0000:00:1d.7
Sep 30 11:11:37 localhost kernel: [4295540.354000] ehci_hcd 0000:00:1d.7: USB
2.0 initialized, EHCI 1.00, driver 10 Dec 2004
Sep 30 11:11:37 localhost kernel: [4295540.356000] hub 4-0:1.0: USB hub found
Sep 30 11:11:37 localhost kernel: [4295540.356000] hub 4-0:1.0: 6 ports detected
Sep 30 11:11:37 localhost dhclient: There is already a pid file
/var/run/dhclient.eth1.pid with pid 0
Sep 30 11:11:37 localhost dhclient: Internet Systems Consortium DHCP Client V3.0.2
Sep 30 11:11:37 localhost dhclient: Copyright 2004 Internet Systems Consortium.
Sep 30 11:11:37 localhost dhclient: All rights reserved.
Sep 30 11:11:37 localhost dhclient: For info, please visit
http://www.isc.org/products/DHCP
Sep 30 11:11:37 localhost dhclient:
Sep 30 11:11:37 localhost dhclient: sit0: unknown hardware address type 776
Sep 30 11:11:37 localhost kernel: [4295540.467000] bridge-eth1: enabling the bridge
Sep 30 11:11:37 localhost kernel: [4295540.467000] bridge-eth1: up
Sep 30 11:11:37 localhost dhclient: sit0: unknown hardware address type 776
Sep 30 11:11:37 localhost dhclient: Listening on LPF/eth1/00:13:ce:10:b6:35
Sep 30 11:11:37 localhost dhclient: Sending on   LPF/eth1/00:13:ce:10:b6:35
Sep 30 11:11:37 localhost dhclient: Sending on   Socket/fallback
Sep 30 11:11:38 localhost kernel: [4295540.983000] usb 3-1: new full speed USB
device using uhci_hcd and address 2
Sep 30 11:11:38 localhost hcid[7567]: HCI dev 0 registered
Sep 30 11:11:38 localhost hcid[7567]: HCI dev 0 up
Sep 30 11:11:38 localhost hcid[7567]: Starting security manager 0
Sep 30 11:11:39 localhost kernel: [4295542.615000] ACPI: Lid Switch [LID0]
Sep 30 11:11:39 localhost kernel: [4295542.615000] ACPI: Power Button (CM) [PWRB]
Sep 30 11:11:41 localhost dhclient: DHCPDISCOVER on eth1 to 255.255.255.255 port
67 interval 6
Sep 30 11:11:41 localhost dhclient: DHCPOFFER from 192.168.1.6
Sep 30 11:11:41 localhost dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Sep 30 11:11:41 localhost dhclient: DHCPACK from 192.168.1.6
Sep 30 11:11:41 localhost dhclient: bound to 192.168.1.196 -- renewal in 286843
seconds.
Sep 30 11:11:43 localhost usb.agent[9129]:      usbcore: already loaded
Sep 30 11:11:43 localhost usb.agent[9091]:      usbcore: already loaded
Sep 30 11:11:43 localhost usb.agent[9118]:      usbcore: already loaded
Sep 30 11:11:44 localhost usb.agent[9284]:      hci_usb: already loaded
Sep 30 11:11:44 localhost usb.agent[9292]:      hci_usb: already loaded
Sep 30 11:11:44 localhost usb.agent[9298]:      hci_usb: already loaded
Sep 30 11:11:44 localhost usb.agent[9260]:      usbcore: already loaded
Sep 30 11:11:47 localhost kernel: [4295550.885000] eth1: no IPv6 routers present

-- 
Suspend to ram almost works  but has hda timeouts issues
https://launchpad.net/bugs/22907




More information about the kernel-bugs mailing list