Bug 15169 - Long delays while hibernating with ultrabay powered off, unless "shutdown" disk method - T400
Summary: Long delays while hibernating with ultrabay powered off, unless "shutdown" di...
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Power Management
Classification: Unclassified
Component: Hibernation/Suspend (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Zhang Rui
URL:
Keywords:
Depends on:
Blocks: 7216
  Show dependency tree
 
Reported: 2010-01-29 01:36 UTC by Pedro Ribeiro
Modified: 2012-05-24 07:26 UTC (History)
4 users (show)

See Also:
Kernel Version: 2.6.33-rc5
Subsystem:
Regression: No
Bisected commit-id:


Attachments
shows a normal hibernation without the delay (7.76 KB, text/plain)
2010-01-29 01:36 UTC, Pedro Ribeiro
Details
shows a hibernation with the 30 second delay clearly visible in the timestamp (8.32 KB, text/plain)
2010-01-29 01:38 UTC, Pedro Ribeiro
Details
shows a sucessful hibernation with "echo shutdown > /sys/power/disk" (6.96 KB, text/plain)
2010-01-29 01:39 UTC, Pedro Ribeiro
Details
lspci -vvv (13.76 KB, application/octet-stream)
2010-01-29 01:39 UTC, Pedro Ribeiro
Details
acpidump (320.98 KB, application/octet-stream)
2010-02-02 13:27 UTC, Pedro Ribeiro
Details
dmesg with acpi_sleep=old_ordering (59.59 KB, text/plain)
2010-03-03 17:49 UTC, Pedro Ribeiro
Details

Description Pedro Ribeiro 2010-01-29 01:36:03 UTC
Created attachment 24775 [details]
shows a normal hibernation without the delay

I have a Lenovo T400 which has a hot-swappable Ultrabay which can take a hard disk, an additional battery or a CD/DVD drive, which is my case.
I have a script (http://www.thinkwiki.org/wiki/How_to_hotswap_UltraBay_devices#Script_for_Ultrabay_eject) which unmounts any filesystem and powers off the ultrabay.
 
This is usually done to remove it afterwards, but in my case I just use this to save 0.5w of power while on battery.

After doing this, while hibernating there is a long 30 second delay on the atomic copy/restore step. During this delay the CPU jumps to 100% as I can hear the fan roaring. Occasionally the whole system freezes and I have to cold boot it, but most of the time it just sits there for 30 seconds and then finishes the hibernation process.

This only happens if the ultrabay device (DVDRAM) is left in the ultrabay powered off. If it is removed, there is no 30 second delay.

I detected this bug using TuxOnIce, but after mailing LKML I discovered it also affects the "vanilla" hibernation present in the kernel. I have this bug at least since .31 (which was when I started using this computer).

Rafael J. Wysocki helped me debug and the attached files are the dmesg logs he requested. During this debug process we discovered that echoing "shutdown" to /sys/power/disk and then hibernating the problem did not occur. 

Quoting from his answer "Most likely, ACPI is trying to do something stupid in _PTS."

Attached are 4 files:
- dmesg_pmTest_ok shows a normal hibernation without the delay
- dmesg_pmTest_bad shows a hibernation with the 30 second delay clearly visible in the timestamp
- dmesg_pmTest_shutdown shows a sucessful hibernation with "echo shutdown > /sys/power/disk"
- lspci -vvv

Regards,
Pedro

output of ver_linux:
Linux Biramilho 2.6.33-rc5 #2 SMP PREEMPT Thu Jan 28 00:48:13 GMT 2010 x86_64 GNU/Linux
 
Gnu C                  4.3.4
Gnu make               3.81
binutils               2.20
util-linux             ./ver_linux: 23: fdformat: not found
mount                  support
module-init-tools      found
Linux C Library        2.10.2
Dynamic linker (ldd)   2.10.2
Procps                 3.2.8
Console-tools          0.2.3
Sh-utils               7.4
Modules Loaded         i915 drm_kms_helper drm i2c_algo_bit sco bridge stp llc bnep rfcomm l2cap crc16 bluetooth vboxnetflt vboxnetadp vboxdrv microcode acpi_cpufreq cpufreq_userspace cpufreq_stats binfmt_misc fuse ext3 jbd mbcache tp_smapi thinkpad_ec snd_hda_codec_conexant uvcvideo videodev v4l1_compat snd_hda_intel v4l2_compat_ioctl32 snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_dummy snd_seq_oss snd_seq_midi snd_rawmidi arc4 ecb snd_seq_midi_event snd_seq i2c_i801 snd_timer psmouse snd_seq_device iwlagn iwlcore thinkpad_acpi led_class wmi snd soundcore i2c_core serio_raw nvram processor battery ac mac80211 snd_page_alloc cfg80211 evdev rfkill xfs exportfs lzo lzo_compress sha256_generic aes_x86_64 aes_generic cbc dm_crypt dm_mod sg sd_mod crc_t10dif usbhid hid uhci_hcd ohci1394 ahci ieee1394 intel_agp libata button scsi_mod video ehci_hcd output usbcore nls_base e1000e agpgart thermal fan thermal_sys


/proc/ioports:
0000-001f : dma1
0020-0021 : pic1
0040-0043 : timer0
004f-004f : smapi
0050-0053 : timer1
0060-0060 : keyboard
0064-0064 : keyboard
0070-0071 : rtc0
0080-008f : dma page reg
00a0-00a1 : pic2
00b2-00b2 : smapi
00c0-00df : dma2
00f0-00ff : fpu
03c0-03df : vga+
0800-080f : pnp 00:02
0cf8-0cff : PCI conf1
1000-107f : pnp 00:02
  1000-1003 : ACPI PM1a_EVT_BLK
  1004-1005 : ACPI PM1a_CNT_BLK
  1008-100b : ACPI PM_TMR
  1010-1015 : ACPI CPU throttle
  1020-102f : ACPI GPE0_BLK
  1050-1050 : ACPI PM2_CNT_BLK
1180-11ff : pnp 00:02
15e0-15ef : pnp 00:02
1600-167f : pnp 00:02
  1600-161f : thinkpad_ec
1680-169f : pnp 00:02
1800-1807 : 0000:00:02.0
1808-180b : 0000:00:1f.2
  1808-180b : ahci
180c-180f : 0000:00:1f.2
  180c-180f : ahci
1810-1817 : 0000:00:1f.2
  1810-1817 : ahci
1818-181f : 0000:00:1f.2
  1818-181f : ahci
1820-183f : 0000:00:19.0
1840-185f : 0000:00:1a.0
  1840-185f : uhci_hcd
1860-187f : 0000:00:1a.1
  1860-187f : uhci_hcd
1880-189f : 0000:00:1a.2
  1880-189f : uhci_hcd
18a0-18bf : 0000:00:1d.0
  18a0-18bf : uhci_hcd
18c0-18df : 0000:00:1d.1
  18c0-18df : uhci_hcd
18e0-18ff : 0000:00:1d.2
  18e0-18ff : uhci_hcd
1c00-1c1f : 0000:00:1f.2
  1c00-1c1f : ahci
1c20-1c3f : 0000:00:1f.3
  1c20-1c3f : i801_smbus
2000-2fff : PCI Bus 0000:02
3000-3fff : PCI Bus 0000:0d
4000-7fff : PCI Bus 0000:15
  4000-40ff : PCI CardBus 0000:16
  4400-44ff : PCI CardBus 0000:16
8000-8fff : PCI Bus 0000:03



/proc/iomem:
00000000-0009ebff : System RAM
0009ec00-0009ffff : reserved
000c0000-000c3fff : pnp 00:00
000c4000-000c7fff : pnp 00:00
000c8000-000cbfff : pnp 00:00
000cc000-000cffff : pnp 00:00
000d0000-000d3fff : pnp 00:00
000dc000-000fffff : reserved
00100000-bd4a0fff : System RAM
  01000000-012d7828 : Kernel code
  012d7829-0166b9bf : Kernel data
  016dc000-017bab43 : Kernel bss
bd4a1000-bd4a6fff : reserved
bd4a7000-bd5b7fff : System RAM
bd5b8000-bd60efff : reserved
bd60f000-bd6c5fff : System RAM
bd6c6000-bd6d0fff : ACPI Non-volatile Storage
bd6d1000-bd6d3fff : ACPI Tables
bd6d4000-bd6d7fff : reserved
bd6d8000-bd6dbfff : ACPI Non-volatile Storage
bd6dc000-bd6defff : reserved
bd6df000-bd705fff : ACPI Non-volatile Storage
bd706000-bd707fff : ACPI Tables
bd708000-bd90efff : reserved
bd90f000-bd99efff : ACPI Non-volatile Storage
bd99f000-bd9fefff : ACPI Tables
bd9ff000-bd9fffff : System RAM
bda00000-bdbfffff : RAM buffer
bdc00000-bfffffff : reserved
c0000000-c01fffff : PCI Bus 0000:02
c0200000-c03fffff : PCI Bus 0000:02
c0400000-c05fffff : PCI Bus 0000:03
c0600000-c0600fff : Intel Flush Page
c4000000-c7ffffff : PCI CardBus 0000:16
d0000000-dfffffff : 0000:00:02.0
e0000000-efffffff : reserved
  e0000000-efffffff : pnp 00:02
    e0000000-e3ffffff : PCI MMCONFIG 0000 [bus 00-3f]
f0000000-f3ffffff : PCI Bus 0000:15
  f0000000-f3ffffff : PCI CardBus 0000:16
f4100000-f41fffff : PCI Bus 0000:0d
f4200000-f42fffff : 0000:00:02.1
f4300000-f43fffff : PCI Bus 0000:03
  f4300000-f4301fff : 0000:03:00.0
    f4300000-f4301fff : iwlagn
f4400000-f47fffff : 0000:00:02.0
f4800000-f7ffffff : PCI Bus 0000:15
  f4800000-f4800fff : 0000:15:00.0
  f4801000-f48017ff : 0000:15:00.1
    f4801000-f48017ff : ohci1394
fa000000-fbffffff : PCI Bus 0000:0d
fc000000-fc01ffff : 0000:00:19.0
  fc000000-fc01ffff : e1000e
fc020000-fc023fff : 0000:00:1b.0
  fc020000-fc023fff : ICH HD audio
fc024000-fc024fff : 0000:00:19.0
  fc024000-fc024fff : e1000e
fc225000-fc2257ff : 0000:00:1f.2
  fc225000-fc2257ff : ahci
fc225800-fc22580f : 0000:00:03.0
fc225c00-fc225fff : 0000:00:1a.7
  fc225c00-fc225fff : ehci_hcd
fc226000-fc2263ff : 0000:00:1d.7
  fc226000-fc2263ff : ehci_hcd
fc226400-fc2264ff : 0000:00:1f.3
fec00000-fec0ffff : reserved
  fec00000-fec003ff : IOAPIC 0
fed00000-fed003ff : HPET 0
  fed00000-fed003ff : reserved
fed10000-fed13fff : reserved
  fed10000-fed13fff : pnp 00:02
fed18000-fed19fff : reserved
  fed18000-fed18fff : pnp 00:02
  fed19000-fed19fff : pnp 00:02
fed1c000-fed8ffff : reserved
  fed1c000-fed1ffff : pnp 00:02
  fed40000-fed44fff : pnp 00:02
  fed45000-fed4bfff : pnp 00:02
fee00000-fee00fff : Local APIC
  fee00000-fee00fff : reserved
ff800000-ffffffff : reserved
100000000-13bffffff : System RAM
Comment 1 Pedro Ribeiro 2010-01-29 01:38:13 UTC
Created attachment 24776 [details]
shows a hibernation with the 30 second delay clearly visible in the timestamp
Comment 2 Pedro Ribeiro 2010-01-29 01:39:00 UTC
Created attachment 24777 [details]
shows a sucessful hibernation with "echo shutdown > /sys/power/disk"
Comment 3 Pedro Ribeiro 2010-01-29 01:39:23 UTC
Created attachment 24778 [details]
lspci -vvv
Comment 4 Len Brown 2010-02-02 02:36:56 UTC
please attach the output from acpidump
Comment 5 Pedro Ribeiro 2010-02-02 13:27:58 UTC
Created attachment 24871 [details]
acpidump
Comment 6 Zhang Rui 2010-03-02 09:23:43 UTC
[  545.764159] ACPI: Waking up from system sleep state S4
[  575.844179] ACPI: \_SB_.PCI0.SATA.PRT1 - docking
[  575.849362] acpi LNXIOBAY:02: parent device:15 should not be sleeping

at least this can give us some clues.
It seems that there is an dock hotplug event before devices are resumed.

please verify if boot option "acpi_sleep=old_ordering" helps.
Comment 7 Pedro Ribeiro 2010-03-02 11:04:06 UTC
Hello,

I tried with "acpi_sleep=old_ordering" but it doesn't help.

Regards
Comment 8 Zhang Rui 2010-03-03 01:38:42 UTC
please attach the dmesg output after hibernate.
Comment 9 Pedro Ribeiro 2010-03-03 17:49:46 UTC
Created attachment 25342 [details]
dmesg with acpi_sleep=old_ordering

Contrary to the logs above, this dmesg output does not show the 30 second delay - however, it still locks up for 30 seconds.
Comment 10 Zhang Rui 2012-01-18 01:57:42 UTC
It's great that kernel bugzilla is back.

can you please verify if the problem still exists in the latest upstream
kernel?
Comment 11 Zhang Rui 2012-05-24 07:26:03 UTC
bug closed as there is no response from the bug reporter.
please feel free to reopen it if the problem still exists in the latest upstream kernel.

Note You need to log in before you can comment on or make changes to this bug.