(09:18:35 AM) smb_tp: CarlFK, I did not look to deeply yet. But I remember there have been several hangs. Can you try noapictimer without too much effort on a 2.6.27? [ 0.000000] Kernel command line: root=UUID=270934eb-b4c5-4f17-87e4-8ebea9d98ed3 ro vga=6 noapictimer doesn't pause at "PCI: Using ACPI for IRQ routing" but does pause at some other places. To continue, don't have to hit the power button - keyboard events, like tapping the shift key, will un pause it. If I hold down the shift key for the whole boot process, it doesn't seem to pause (guessing keyboard repeat?) (10:18:12 AM) CarlFK: smb_tp: so I was trying to note all the places .27 pauses, and i ran out of battery (10:18:56 AM) CarlFK: plugged in, booted, and it seems like it is still pausing, but continuing on its own without me hitting any keys (10:19:17 AM) CarlFK: as the battery charges, does that generate some sort of event, similar to hitting the power button? (10:22:10 AM) smb_tp: CarlFK, I can't say for sure. I won't think so on charge. below is the dmesg from booting with power, then without. when it paused, I gave it about 5 seconds, then tapped the shift key. Used this .py to look for the gaps: dmesgs = open('/mnt/nfs/cw1b/carl/a/dmesg9.txt').read().split('\n') # make a list of (tiems as floats, original line (with ts)) l=[] for i in dmesgs: if i: # skip blank lines (like at the end) ts=i[1:13] # print ts, i l.append( (float(ts), i) ) # look for gaps for i in xrange(len(l)-1): d = l[i+1][0] - l[i][0] if d>1: for x in l[i-3:i+1]: print x[1] print "(pause)" for x in l[i+1:i+3]: print x[1] print gaps in boot while on AC power (on a drained battery, so it was charging too): [ 3.030625] libata version 3.00 loaded. [ 3.059201] usb usb1: configuration #1 chosen from 1 choice [ 3.059298] hub 1-0:1.0: USB hub found [ 3.059370] hub 1-0:1.0: 7 ports detected (pause) [ 58.727075] Clocksource tsc unstable (delta = 4398044420614 ns) [ 58.728022] ACPI: PCI Interrupt Link [Z018] enabled at IRQ 18 [ 58.728354] ohci_hcd 0000:00:04.0: irq 18, io mem 0xf6487000 [ 58.834595] usb usb2: configuration #1 chosen from 1 choice [ 58.834689] hub 2-0:1.0: USB hub found [ 58.834756] hub 2-0:1.0: 2 ports detected (pause) [ 147.069064] ACPI: PCI Interrupt Link [LUS2] enabled at IRQ 22 [ 147.069137] ehci_hcd 0000:00:02.1: PCI INT B -> Link[LUS2] -> GSI 22 (level, low) -> IRQ 22 [ 147.069317] ehci_hcd 0000:00:02.1: new USB bus registered, assigned bus number 3 [ 147.069418] ehci_hcd 0000:00:02.1: debug port 1 [ 147.069486] ehci_hcd 0000:00:02.1: cache line size of 64 is not supported [ 147.069501] ehci_hcd 0000:00:02.1: irq 22, io mem 0xf6489000 (pause) [ 161.672469] usb 2-1: new full speed USB device using ohci_hcd and address 2 [ 174.346769] ehci_hcd 0000:00:02.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 147.069418] ehci_hcd 0000:00:02.1: debug port 1 [ 147.069486] ehci_hcd 0000:00:02.1: cache line size of 64 is not supported [ 147.069501] ehci_hcd 0000:00:02.1: irq 22, io mem 0xf6489000 [ 161.672469] usb 2-1: new full speed USB device using ohci_hcd and address 2 (pause) [ 174.346769] ehci_hcd 0000:00:02.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 174.346983] usb usb3: configuration #1 chosen from 1 choice [ 174.346769] ehci_hcd 0000:00:02.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 174.346983] usb usb3: configuration #1 chosen from 1 choice [ 174.347071] hub 3-0:1.0: USB hub found [ 174.347139] hub 3-0:1.0: 7 ports detected (pause) [ 221.674307] ACPI: PCI Interrupt Link [Z019] enabled at IRQ 22 [ 221.674376] ehci_hcd 0000:00:04.1: PCI INT B -> Link[Z019] -> GSI 22 (level, low) -> IRQ 22 [ 221.674549] ehci_hcd 0000:00:04.1: new USB bus registered, assigned bus number 4 [ 221.674647] ehci_hcd 0000:00:04.1: debug port 1 [ 221.674710] ehci_hcd 0000:00:04.1: cache line size of 64 is not supported [ 221.674717] ehci_hcd 0000:00:04.1: irq 22, io mem 0xf6489400 (pause) [ 514.258282] ehci_hcd 0000:00:04.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 514.258503] usb usb4: configuration #1 chosen from 1 choice [ 514.258282] ehci_hcd 0000:00:04.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 514.258503] usb usb4: configuration #1 chosen from 1 choice [ 514.258596] hub 4-0:1.0: USB hub found [ 514.258662] hub 4-0:1.0: 2 ports detected (pause) [ 579.099305] usb 2-1: device not accepting address 2, error -62 [ 579.099716] pata_acpi 0000:00:06.0: setting latency timer to 64 [ 579.101282] ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 20 [ 579.101352] forcedeth 0000:00:0a.0: PCI INT A -> Link[LMAC] -> GSI 20 (level, low) -> IRQ 20 [ 579.101429] forcedeth 0000:00:0a.0: setting latency timer to 64 [ 579.170702] hub 2-0:1.0: unable to enumerate USB device on port 1 (pause) [ 689.746786] BUG: soft lockup - CPU#0 stuck for 103s! [swapper:0] [ 689.746786] Modules linked in: ohci1394(+) pata_acpi(+) forcedeth(+) ieee1394 libata ehci_hcd(+) ohci_hcd(+) scsi_mod dock usbcore thermal processor fan uvesafb cn fuse fbcon tileblit font bitblit softcursor [ 689.746786] [] cpuidle_idle_call+0x7b/0xd0 [ 689.746786] [] cpu_idle+0x7d/0x130 [ 689.746786] [] start_secondary+0x9d/0xd4 [ 689.746786] ======================= (pause) [ 710.157916] forcedeth 0000:00:0a.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:1e:68:09:25:f6 [ 710.164052] forcedeth 0000:00:0a.0: highdma pwrctl mgmt timirq lnktim msi desc-v3 [ 710.228859] ata1: SATA max UDMA/133 abar m8192@0xf6484000 port 0xf6484100 irq 221 [ 710.228934] ata2: SATA max UDMA/133 abar m8192@0xf6484000 port 0xf6484180 irq 221 [ 710.229032] ata3: SATA max UDMA/133 abar m8192@0xf6484000 port 0xf6484200 irq 221 [ 710.229106] ata4: SATA max UDMA/133 abar m8192@0xf6484000 port 0xf6484280 irq 221 (pause) [ 854.608814] BUG: soft lockup - CPU#0 stuck for 134s! [events/0:9] [ 854.608880] Modules linked in: pata_amd(+) ahci(+) ohci1394 pata_acpi forcedeth ieee1394 libata ehci_hcd ohci_hcd scsi_mod dock usbcore thermal processor fan uvesafb cn fuse fbcon tileblit font bitblit softcursor [ 854.610388] [] kthread+0x41/0x80 [ 854.610388] [] ? kthread+0x0/0x80 [ 854.610388] [] kernel_thread_helper+0x7/0x10 [ 854.610388] ======================= (pause) [ 911.134492] ieee1394: Host added: ID:BUS[0-00:1023] GUID[00241b00964cac00] [ 922.730364] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 854.610388] [] ? kthread+0x0/0x80 [ 854.610388] [] kernel_thread_helper+0x7/0x10 [ 854.610388] ======================= [ 911.134492] ieee1394: Host added: ID:BUS[0-00:1023] GUID[00241b00964cac00] (pause) [ 922.730364] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 922.731215] ata1.00: ATA-8: Hitachi HTS542525K9SA00, BBFOC32P, max UDMA/100 [ 922.730364] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 922.731215] ata1.00: ATA-8: Hitachi HTS542525K9SA00, BBFOC32P, max UDMA/100 [ 922.731280] ata1.00: 488397168 sectors, multi 16: LBA48 [ 922.732297] ata1.00: configured for UDMA/100 (pause) [ 1009.886149] usb 4-2: new high speed USB device using ehci_hcd and address 3 [ 1009.889878] BUG: soft lockup - CPU#1 stuck for 81s! [swapper:0] [ 1009.889878] [] cpuidle_idle_call+0x7b/0xd0 [ 1009.889878] [] cpu_idle+0x7d/0x130 [ 1009.889878] [] start_secondary+0x9d/0xd4 [ 1009.889878] ======================= (pause) [ 1033.340262] ata2: SATA link down (SStatus 0 SControl 300) [ 1195.682149] BUG: soft lockup - CPU#0 stuck for 151s! [swapper:0] [ 1009.889878] [] cpu_idle+0x7d/0x130 [ 1009.889878] [] start_secondary+0x9d/0xd4 [ 1009.889878] ======================= [ 1033.340262] ata2: SATA link down (SStatus 0 SControl 300) (pause) [ 1195.682149] BUG: soft lockup - CPU#0 stuck for 151s! [swapper:0] [ 1195.682149] Modules linked in: pata_amd(+) ahci(+) ohci1394 pata_acpi forcedeth ieee1394 libata ehci_hcd ohci_hcd scsi_mod dock usbcore thermal processor fan uvesafb cn fuse fbcon tileblit font bitblit softcursor [ 1195.682150] [] cpu_idle+0x7d/0x130 [ 1195.682150] [] start_secondary+0x9d/0xd4 [ 1195.682150] ======================= [ 1195.778736] usb 4-2: configuration #1 chosen from 1 choice (pause) [ 1222.660890] ata3: SATA link down (SStatus 0 SControl 300) [ 1416.107718] ata4: SATA link down (SStatus 0 SControl 300) [ 1195.682150] [] start_secondary+0x9d/0xd4 [ 1195.682150] ======================= [ 1195.778736] usb 4-2: configuration #1 chosen from 1 choice [ 1222.660890] ata3: SATA link down (SStatus 0 SControl 300) (pause) [ 1416.107718] ata4: SATA link down (SStatus 0 SControl 300) [ 1416.107974] scsi 0:0:0:0: Direct-Access ATA Hitachi HTS54252 BBFO PQ: 0 ANSI: 5 [ 1416.517339] Uniform CD-ROM driver Revision: 3.20 [ 1416.517339] sr 4:0:0:0: Attached scsi CD-ROM sr0 [ 1416.593039] usb 2-1: new full speed USB device using ohci_hcd and address 4 [ 1416.807748] usb 2-1: configuration #1 chosen from 1 choice (pause) [ 1451.031759] PM: Starting manual resume from disk [ 1451.031821] PM: Resume from partition 8:5 [ 1451.035855] PM: Basic memory bitmaps created [ 1451.085156] PM: Basic memory bitmaps freed [ 1451.103085] EXT3-fs: INFO: recovery required on readonly filesystem. [ 1451.103152] EXT3-fs: write access will be enabled during recovery. (pause) [ 1510.770094] kjournald starting. Commit interval 5 seconds [ 1511.380732] EXT3-fs: recovery complete. [ 1451.103152] EXT3-fs: write access will be enabled during recovery. [ 1510.770094] kjournald starting. Commit interval 5 seconds [ 1511.380732] EXT3-fs: recovery complete. [ 1511.380732] EXT3-fs: mounted filesystem with ordered data mode. (pause) [ 1635.455401] BUG: soft lockup - CPU#0 stuck for 81s! [swapper:0] [ 1635.455401] Modules linked in: ext3 jbd mbcache sr_mod cdrom sg sd_mod crc_t10dif ata_generic pata_amd ahci ohci1394 pata_acpi forcedeth ieee1394 libata ehci_hcd ohci_hcd scsi_mod dock usbcore thermal processor fan uvesafb cn fuse fbcon tileblit font bitblit softcursor [ 1635.455404] [] cpuidle_idle_call+0x7b/0xd0 [ 1635.455404] [] cpu_idle+0x7d/0x130 [ 1635.455404] [] start_secondary+0x9d/0xd4 [ 1635.455404] ======================= (pause) [ 1720.538936] BUG: soft lockup - CPU#0 stuck for 76s! [swapper:0] [ 1720.538936] Modules linked in: ext3 jbd mbcache sr_mod cdrom sg sd_mod crc_t10dif ata_generic pata_amd ahci ohci1394 pata_acpi forcedeth ieee1394 libata ehci_hcd ohci_hcd scsi_mod dock usbcore thermal processor fan uvesafb cn fuse fbcon tileblit font bitblit softcursor [ 1720.538936] [] cpuidle_idle_call+0x7b/0xd0 [ 1720.538936] [] cpu_idle+0x7d/0x130 [ 1720.538936] [] rest_init+0x53/0x60 [ 1720.538936] ======================= (pause) [ 1731.243875] udevd version 124 started [ 1732.247991] input: Power Button (FF) as /class/input/input2 [ 1720.538936] [] cpu_idle+0x7d/0x130 [ 1720.538936] [] rest_init+0x53/0x60 [ 1720.538936] ======================= [ 1731.243875] udevd version 124 started (pause) [ 1732.247991] input: Power Button (FF) as /class/input/input2 [ 1732.300166] ACPI: Power Button (FF) [PWRF] [ 1737.838091] type=1505 audit(1220371046.957:2): operation="profile_load" name="/usr/share/gdm/guest-session/Xsession" name2="default" pid=4271 [ 1738.028675] type=1505 audit(1220371047.149:3): operation="profile_load" name="/usr/lib/cups/backend/cups-pdf" name2="default" pid=4276 [ 1738.028884] type=1505 audit(1220371047.149:4): operation="profile_load" name="/usr/sbin/cupsd" name2="default" pid=4276 [ 1738.129351] ip_tables: (C) 2000-2006 Netfilter Core Team (pause) [ 1741.249008] powernow-k8: Found 1 AMD Turion(tm) 64 X2 Mobile Technology TL-60 processors (2 cpu cores) (version 2.20.00) [ 1741.252006] powernow-k8: 0 : fid 0xc (2000 MHz), vid 0x11 [ 1741.252006] powernow-k8: 0 : fid 0xc (2000 MHz), vid 0x11 [ 1741.252006] powernow-k8: 1 : fid 0xa (1800 MHz), vid 0x12 [ 1741.252006] powernow-k8: 2 : fid 0x8 (1600 MHz), vid 0x13 [ 1741.252006] powernow-k8: 3 : fid 0x0 (800 MHz), vid 0x1e (pause) [ 1742.556006] warning: `avahi-daemon' uses 32-bit capabilities (legacy support in use) [ 1743.016265] NET: Registered protocol family 10 [ 1743.016265] NET: Registered protocol family 10 [ 1743.018008] lo: Disabled Privacy Extensions [ 1743.145006] apm: BIOS not found. [ 1743.573808] ppdev: user-space parallel port driver (pause) [ 1747.873201] Bluetooth: L2CAP ver 2.10 [ 1747.873217] Bluetooth: L2CAP socket layer initialized [ 1747.873217] Bluetooth: L2CAP socket layer initialized [ 1747.921243] Bluetooth: RFCOMM socket layer initialized [ 1747.921871] Bluetooth: RFCOMM TTY layer initialized [ 1747.921896] Bluetooth: RFCOMM ver 1.10 (pause) [ 1753.207599] eth0: no link during initialization. [ 1753.208135] ADDRCONF(NETDEV_UP): eth0: link is not ready [ 1754.329122] wlan0: RX AssocResp from 00:e0:98:55:95:2c (capab=0x421 status=0 aid=2) [ 1754.329130] wlan0: associated [ 1754.329842] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 1754.330845] wlan0: disassociating by local choice (reason=3) (pause) [ 1764.728018] wlan0: no IPv6 routers present [ 1769.125789] wlan0: authenticate with AP 00:e0:98:55:95:2c [ 1754.329130] wlan0: associated [ 1754.329842] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 1754.330845] wlan0: disassociating by local choice (reason=3) [ 1764.728018] wlan0: no IPv6 routers present (pause) [ 1769.125789] wlan0: authenticate with AP 00:e0:98:55:95:2c [ 1769.127237] wlan0: authenticated [ 1769.127237] wlan0: authenticated [ 1769.127246] wlan0: associate with AP 00:e0:98:55:95:2c [ 1769.132365] wlan0: RX ReassocResp from 00:e0:98:55:95:2c (capab=0x421 status=0 aid=2) [ 1769.132381] wlan0: associated (pause) [ 1775.866182] RPC: Registered udp transport module. [ 1775.866197] RPC: Registered tcp transport module.