Hi all,
I have created today's linux-next tree at
git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git.
You can see which trees have been included by looking in the Next/Trees
file in the source. There are also quilt-import.log and merge.log files
in the Next directory. Between each merge, the tree was built with
allmodconfig for both powerpc and x86_64.
There only one minor merge problem and a few build failures (the two in
Linus' tree have been fixed and the other reported).
We are up to 32 trees, more are welcome (even if they are currently
empty).
Status of my local build tests is at
http://kisskb.ellerman.id.au/kisskb/branch/9/.
--
Cheers,
Stephen Rothwell [email protected]
Stephen Rothwell wrote:
> Hi all,
>
> I have created today's linux-next tree at
> git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git.
>
> You can see which trees have been included by looking in the Next/Trees
> file in the source. There are also quilt-import.log and merge.log files
> in the Next directory. Between each merge, the tree was built with
> allmodconfig for both powerpc and x86_64.
>
> There only one minor merge problem and a few build failures (the two in
> Linus' tree have been fixed and the other reported).
>
> We are up to 32 trees, more are welcome (even if they are currently
> empty).
>
> Status of my local build tests is at
> http://kisskb.ellerman.id.au/kisskb/branch/9/.
>
I tried something with this tree that I haven't tried in a while - Suspend
to RAM. It has not often worked for me in the past with any tree, but
normally there isn't any information in the log that indicates the cause of
the failure.
Today was different - I attempted to suspend and resume from the console,
and the machine did not come back up. I found the following in my log -
any help would be appreciated.
Feb 24 13:59:56 alekhine kernel: [ 456.497875] PM: Syncing filesystems ... done.
Feb 24 14:00:20 alekhine kernel: [ 456.507273] Freezing user space processes ... (elapsed 0.00 seconds) done.
Feb 24 14:00:20 alekhine kernel: [ 456.510447] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
Feb 24 14:00:20 alekhine kernel: [ 456.510754] ACPI: Preparing to enter system sleep state S3
Feb 24 14:00:20 alekhine kernel: [ 456.612370] Suspending console(s)
Feb 24 14:00:20 alekhine kernel: [ 456.616254] sd 3:0:0:0: [sda] Synchronizing SCSI cache
Feb 24 14:00:20 alekhine kernel: [ 456.616521] sd 3:0:0:0: [sda] Stopping disk
Feb 24 14:00:20 alekhine kernel: [ 456.618221] ACPI: PCI interrupt for device 0000:00:11.5 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.630296] ACPI: PCI interrupt for device 0000:00:10.4 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.641085] ACPI: PCI interrupt for device 0000:00:10.3 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.651877] ACPI: PCI interrupt for device 0000:00:10.2 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.662716] ACPI: PCI interrupt for device 0000:00:10.1 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.673550] ACPI: PCI interrupt for device 0000:00:10.0 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.684385] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.695056] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
Feb 24 14:00:20 alekhine kernel: [ 456.705856] 5 locks held by bash/2929:
Feb 24 14:00:20 alekhine kernel: [ 456.705856] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.705856] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
Feb 24 14:00:20 alekhine kernel: [ 456.705856] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
Feb 24 14:00:20 alekhine kernel: [ 456.705856] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
Feb 24 14:00:20 alekhine kernel: [ 456.705856] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
Feb 24 14:00:20 alekhine kernel: [ 456.705856] irq event stamp: 19374
Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
Feb 24 14:00:20 alekhine kernel: [ 456.705856] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01177c7>] __schedule_bug+0x58/0x5f
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0325b43>] schedule+0x67/0x3b3
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c39>] ? __mod_timer+0x8d/0x98
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326043>] schedule_timeout+0x73/0x91
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c012185c>] ? process_timeout+0x0/0xa
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c54>] msleep+0x10/0x16
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e0e51>] pci_set_power_state+0x17f/0x200
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0244917>] velocity_suspend+0x2e9/0x302
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0133854>] ? mark_held_locks+0x4e/0x66
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e249e>] pci_device_suspend+0x1b/0x4b
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c023c625>] device_suspend+0x192/0x251
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c1c>] enter_state+0xb2/0x100
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138cfe>] state_store+0x94/0xac
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c6a>] ? state_store+0x0/0xac
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01d50c5>] kobj_attr_store+0x1a/0x22
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c018969f>] sysfs_write_file+0xb8/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01597d7>] vfs_write+0x88/0xf8
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0159c6e>] sys_write+0x3b/0x60
Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
Feb 24 14:00:20 alekhine kernel: [ 456.705856] =======================
Feb 24 14:00:20 alekhine kernel: [ 456.716732]
Feb 24 14:00:20 alekhine kernel: [ 456.716732] =================================
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [ INFO: inconsistent lock state ]
Feb 24 14:00:20 alekhine kernel: [ 456.716732] 2.6.25-rc2-next-20080224 #58
Feb 24 14:00:20 alekhine kernel: [ 456.716732] ---------------------------------
Feb 24 14:00:20 alekhine kernel: [ 456.716732] inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
Feb 24 14:00:20 alekhine kernel: [ 456.716732] bash/2929 [HC0[0]:SC0[0]:HE1:SE1] takes:
Feb 24 14:00:20 alekhine kernel: [ 456.716732] (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
Feb 24 14:00:20 alekhine kernel: [ 456.716732] {in-hardirq-W} state was registered at:
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c013416b>] __lock_acquire+0x3ac/0xb43
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0134963>] lock_acquire+0x61/0x7d
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c03279fb>] _spin_lock+0x23/0x32
Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0243940>] velocity_intr+0x24/0x579
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c02ca5e1>] snd_via8233_interrupt+0xdc/0xe7
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a884>] handle_fasteoi_irq+0x95/0xab
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01398b3>] handle_IRQ_event+0x1a/0x46
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a88d>] handle_fasteoi_irq+0x9e/0xab
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a7ef>] handle_fasteoi_irq+0x0/0xab
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0105010>] do_IRQ+0xab/0xd4
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<ffffffff>] 0xffffffff
Feb 24 14:00:20 alekhine kernel: [ 456.716733] irq event stamp: 19374
Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
Feb 24 14:00:20 alekhine kernel: [ 456.716733]
Feb 24 14:00:20 alekhine kernel: [ 456.716733] other info that might help us debug this:
Feb 24 14:00:20 alekhine kernel: [ 456.716733] 5 locks held by bash/2929:
Feb 24 14:00:20 alekhine kernel: [ 456.716733] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.716733] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
Feb 24 14:00:20 alekhine kernel: [ 456.716733] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
Feb 24 14:00:20 alekhine kernel: [ 456.716733] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
Feb 24 14:00:20 alekhine kernel: [ 456.716733] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
Feb 24 14:00:20 alekhine kernel: [ 456.716733]
Feb 24 14:00:20 alekhine kernel: [ 456.716733] stack backtrace:
Feb 24 14:00:20 alekhine kernel: [ 456.716733] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0132d3b>] print_usage_bug+0x10d/0x11a
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013361f>] mark_lock+0x1f1/0x3d8
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] mark_held_locks+0x4e/0x66
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] ? _spin_unlock_irq+0x22/0x42
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339c7>] trace_hardirqs_on+0xcf/0x120
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] _spin_unlock_irq+0x22/0x42
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0117322>] finish_task_switch+0x46/0x7d
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01172dc>] ? finish_task_switch+0x0/0x7d
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0325e39>] schedule+0x35d/0x3b3
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c39>] ? __mod_timer+0x8d/0x98
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326043>] schedule_timeout+0x73/0x91
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c012185c>] ? process_timeout+0x0/0xa
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c54>] msleep+0x10/0x16
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e0e51>] pci_set_power_state+0x17f/0x200
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0244917>] velocity_suspend+0x2e9/0x302
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] ? mark_held_locks+0x4e/0x66
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e249e>] pci_device_suspend+0x1b/0x4b
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c023c625>] device_suspend+0x192/0x251
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c1c>] enter_state+0xb2/0x100
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138cfe>] state_store+0x94/0xac
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c6a>] ? state_store+0x0/0xac
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01d50c5>] kobj_attr_store+0x1a/0x22
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c018969f>] sysfs_write_file+0xb8/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01597d7>] vfs_write+0x88/0xf8
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0159c6e>] sys_write+0x3b/0x60
Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
Feb 24 14:00:20 alekhine kernel: [ 456.716733] =======================
Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check architecture supported.
Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check reporting enabled on CPU#0.
Feb 24 14:00:20 alekhine kernel: [ 456.733181] Velocity is AUTO mode
Feb 24 14:00:20 alekhine kernel: [ 456.733182] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 24 14:00:20 alekhine kernel: [ 456.733184] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 24 14:00:20 alekhine kernel: [ 456.733185] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
Feb 24 14:00:20 alekhine kernel: [ 456.733185] usb usb2: root hub lost power or was reset
Feb 24 14:00:20 alekhine kernel: [ 456.744080] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
Feb 24 14:00:20 alekhine kernel: [ 456.744080] usb usb3: root hub lost power or was reset
Feb 24 14:00:20 alekhine kernel: [ 456.754997] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
Feb 24 14:00:20 alekhine kernel: [ 456.754997] usb usb4: root hub lost power or was reset
Feb 24 14:00:20 alekhine kernel: [ 456.765914] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
Feb 24 14:00:20 alekhine kernel: [ 456.765914] usb usb5: root hub lost power or was reset
Feb 24 14:00:20 alekhine kernel: [ 456.776818] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
Feb 24 14:00:20 alekhine kernel: [ 456.787745] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
Feb 24 14:00:20 alekhine kernel: [ 456.789881] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
Feb 24 14:00:20 alekhine kernel: [ 456.789961] sd 3:0:0:0: [sda] Starting disk
Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 457.340841] ata3.00: configured for UDMA/33
Feb 24 14:00:20 alekhine kernel: [ 457.528347] ata3.01: configured for UDMA/33
Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
Feb 24 14:00:20 alekhine kernel: [ 460.978040] ata4.00: configured for UDMA/100
Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write Protect is off
Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 24 14:00:20 alekhine kernel: [ 461.524370] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
Feb 24 14:00:20 alekhine kernel: [ 461.569374] done.
Feb 24 14:00:21 alekhine kernel: [ 461.755858] usb 2-1: new low speed USB device using uhci_hcd and address 4
Feb 24 14:00:21 alekhine kernel: [ 461.915256] usb 2-1: configuration #1 chosen from 1 choice
Feb 24 14:00:21 alekhine kernel: [ 461.955599] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
Feb 24 14:00:21 alekhine kernel: [ 461.979344] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
Feb 24 14:00:21 alekhine kernel: [ 461.979553] usb 2-2: USB disconnect, address 3
Feb 24 14:00:21 alekhine kernel: [ 462.236114] usb 2-2: new low speed USB device using uhci_hcd and address 5
Feb 24 14:00:21 alekhine kernel: [ 462.405538] usb 2-2: configuration #1 chosen from 1 choice
Feb 24 14:00:21 alekhine kernel: [ 462.439929] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
Feb 24 14:00:21 alekhine kernel: [ 462.463834] input: USB HID v1.11 Keyboard [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
Feb 24 14:00:21 alekhine kernel: [ 462.492181] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
Feb 24 14:00:21 alekhine kernel: [ 462.517592] input: USB HID v1.11 Device [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
On Sunday, 24 of February 2008, Kevin Winchester wrote:
> Stephen Rothwell wrote:
> > Hi all,
Hi,
> > I have created today's linux-next tree at
> > git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git.
> >
> > You can see which trees have been included by looking in the Next/Trees
> > file in the source. There are also quilt-import.log and merge.log files
> > in the Next directory. Between each merge, the tree was built with
> > allmodconfig for both powerpc and x86_64.
> >
> > There only one minor merge problem and a few build failures (the two in
> > Linus' tree have been fixed and the other reported).
> >
> > We are up to 32 trees, more are welcome (even if they are currently
> > empty).
> >
> > Status of my local build tests is at
> > http://kisskb.ellerman.id.au/kisskb/branch/9/.
> >
>
> I tried something with this tree that I haven't tried in a while - Suspend
> to RAM. It has not often worked for me in the past with any tree, but
> normally there isn't any information in the log that indicates the cause of
> the failure.
>
> Today was different - I attempted to suspend and resume from the console,
> and the machine did not come back up. I found the following in my log -
> any help would be appreciated.
>
> Feb 24 13:59:56 alekhine kernel: [ 456.497875] PM: Syncing filesystems ... done.
> Feb 24 14:00:20 alekhine kernel: [ 456.507273] Freezing user space processes ... (elapsed 0.00 seconds) done.
> Feb 24 14:00:20 alekhine kernel: [ 456.510447] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> Feb 24 14:00:20 alekhine kernel: [ 456.510754] ACPI: Preparing to enter system sleep state S3
> Feb 24 14:00:20 alekhine kernel: [ 456.612370] Suspending console(s)
> Feb 24 14:00:20 alekhine kernel: [ 456.616254] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> Feb 24 14:00:20 alekhine kernel: [ 456.616521] sd 3:0:0:0: [sda] Stopping disk
> Feb 24 14:00:20 alekhine kernel: [ 456.618221] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.630296] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.641085] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.651877] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.662716] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.673550] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.684385] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.695056] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] 5 locks held by bash/2929:
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] irq event stamp: 19374
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01177c7>] __schedule_bug+0x58/0x5f
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0325b43>] schedule+0x67/0x3b3
Well, could you check what's at schedule+0x67, please?
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c39>] ? __mod_timer+0x8d/0x98
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326043>] schedule_timeout+0x73/0x91
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c012185c>] ? process_timeout+0x0/0xa
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c54>] msleep+0x10/0x16
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e0e51>] pci_set_power_state+0x17f/0x200
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0244917>] velocity_suspend+0x2e9/0x302
velocity_suspend() seems to be at fault.
At the moment I have to take care of some more urgent things, I'll have a look
at it tomorrow.
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0133854>] ? mark_held_locks+0x4e/0x66
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e249e>] pci_device_suspend+0x1b/0x4b
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c023c625>] device_suspend+0x192/0x251
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c1c>] enter_state+0xb2/0x100
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138cfe>] state_store+0x94/0xac
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c6a>] ? state_store+0x0/0xac
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01d50c5>] kobj_attr_store+0x1a/0x22
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c018969f>] sysfs_write_file+0xb8/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01597d7>] vfs_write+0x88/0xf8
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0159c6e>] sys_write+0x3b/0x60
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
> Feb 24 14:00:20 alekhine kernel: [ 456.705856] =======================
> Feb 24 14:00:20 alekhine kernel: [ 456.716732]
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] =================================
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [ INFO: inconsistent lock state ]
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] 2.6.25-rc2-next-20080224 #58
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] ---------------------------------
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] bash/2929 [HC0[0]:SC0[0]:HE1:SE1] takes:
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] {in-hardirq-W} state was registered at:
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c013416b>] __lock_acquire+0x3ac/0xb43
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0134963>] lock_acquire+0x61/0x7d
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c03279fb>] _spin_lock+0x23/0x32
> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0243940>] velocity_intr+0x24/0x579
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c02ca5e1>] snd_via8233_interrupt+0xdc/0xe7
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a884>] handle_fasteoi_irq+0x95/0xab
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01398b3>] handle_IRQ_event+0x1a/0x46
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a88d>] handle_fasteoi_irq+0x9e/0xab
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a7ef>] handle_fasteoi_irq+0x0/0xab
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0105010>] do_IRQ+0xab/0xd4
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<ffffffff>] 0xffffffff
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] irq event stamp: 19374
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
> Feb 24 14:00:20 alekhine kernel: [ 456.716733]
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] other info that might help us debug this:
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] 5 locks held by bash/2929:
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
> Feb 24 14:00:20 alekhine kernel: [ 456.716733]
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] stack backtrace:
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0132d3b>] print_usage_bug+0x10d/0x11a
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013361f>] mark_lock+0x1f1/0x3d8
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] mark_held_locks+0x4e/0x66
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] ? _spin_unlock_irq+0x22/0x42
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339c7>] trace_hardirqs_on+0xcf/0x120
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] _spin_unlock_irq+0x22/0x42
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0117322>] finish_task_switch+0x46/0x7d
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01172dc>] ? finish_task_switch+0x0/0x7d
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0325e39>] schedule+0x35d/0x3b3
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c39>] ? __mod_timer+0x8d/0x98
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326043>] schedule_timeout+0x73/0x91
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c012185c>] ? process_timeout+0x0/0xa
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c54>] msleep+0x10/0x16
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e0e51>] pci_set_power_state+0x17f/0x200
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0244917>] velocity_suspend+0x2e9/0x302
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] ? mark_held_locks+0x4e/0x66
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e249e>] pci_device_suspend+0x1b/0x4b
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c023c625>] device_suspend+0x192/0x251
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c1c>] enter_state+0xb2/0x100
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138cfe>] state_store+0x94/0xac
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c6a>] ? state_store+0x0/0xac
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01d50c5>] kobj_attr_store+0x1a/0x22
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c018969f>] sysfs_write_file+0xb8/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01597d7>] vfs_write+0x88/0xf8
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0159c6e>] sys_write+0x3b/0x60
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
> Feb 24 14:00:20 alekhine kernel: [ 456.716733] =======================
> Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check architecture supported.
> Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check reporting enabled on CPU#0.
> Feb 24 14:00:20 alekhine kernel: [ 456.733181] Velocity is AUTO mode
> Feb 24 14:00:20 alekhine kernel: [ 456.733182] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 24 14:00:20 alekhine kernel: [ 456.733184] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 24 14:00:20 alekhine kernel: [ 456.733185] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 24 14:00:20 alekhine kernel: [ 456.733185] usb usb2: root hub lost power or was reset
> Feb 24 14:00:20 alekhine kernel: [ 456.744080] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 24 14:00:20 alekhine kernel: [ 456.744080] usb usb3: root hub lost power or was reset
> Feb 24 14:00:20 alekhine kernel: [ 456.754997] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 24 14:00:20 alekhine kernel: [ 456.754997] usb usb4: root hub lost power or was reset
> Feb 24 14:00:20 alekhine kernel: [ 456.765914] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 24 14:00:20 alekhine kernel: [ 456.765914] usb usb5: root hub lost power or was reset
> Feb 24 14:00:20 alekhine kernel: [ 456.776818] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> Feb 24 14:00:20 alekhine kernel: [ 456.787745] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> Feb 24 14:00:20 alekhine kernel: [ 456.789881] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> Feb 24 14:00:20 alekhine kernel: [ 456.789961] sd 3:0:0:0: [sda] Starting disk
> Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 457.340841] ata3.00: configured for UDMA/33
> Feb 24 14:00:20 alekhine kernel: [ 457.528347] ata3.01: configured for UDMA/33
> Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> Feb 24 14:00:20 alekhine kernel: [ 460.978040] ata4.00: configured for UDMA/100
> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write Protect is off
> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> Feb 24 14:00:20 alekhine kernel: [ 461.524370] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> Feb 24 14:00:20 alekhine kernel: [ 461.569374] done.
> Feb 24 14:00:21 alekhine kernel: [ 461.755858] usb 2-1: new low speed USB device using uhci_hcd and address 4
> Feb 24 14:00:21 alekhine kernel: [ 461.915256] usb 2-1: configuration #1 chosen from 1 choice
> Feb 24 14:00:21 alekhine kernel: [ 461.955599] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> Feb 24 14:00:21 alekhine kernel: [ 461.979344] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> Feb 24 14:00:21 alekhine kernel: [ 461.979553] usb 2-2: USB disconnect, address 3
> Feb 24 14:00:21 alekhine kernel: [ 462.236114] usb 2-2: new low speed USB device using uhci_hcd and address 5
> Feb 24 14:00:21 alekhine kernel: [ 462.405538] usb 2-2: configuration #1 chosen from 1 choice
> Feb 24 14:00:21 alekhine kernel: [ 462.439929] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> Feb 24 14:00:21 alekhine kernel: [ 462.463834] input: USB HID v1.11 Keyboard [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> Feb 24 14:00:21 alekhine kernel: [ 462.492181] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> Feb 24 14:00:21 alekhine kernel: [ 462.517592] input: USB HID v1.11 Device [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
Rafael J. Wysocki wrote:
> On Sunday, 24 of February 2008, Kevin Winchester wrote:
>
>> Today was different - I attempted to suspend and resume from the console,
>> and the machine did not come back up. I found the following in my log -
>> any help would be appreciated.
>>
>> Feb 24 13:59:56 alekhine kernel: [ 456.497875] PM: Syncing filesystems ... done.
>> Feb 24 14:00:20 alekhine kernel: [ 456.507273] Freezing user space processes ... (elapsed 0.00 seconds) done.
>> Feb 24 14:00:20 alekhine kernel: [ 456.510447] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
>> Feb 24 14:00:20 alekhine kernel: [ 456.510754] ACPI: Preparing to enter system sleep state S3
>> Feb 24 14:00:20 alekhine kernel: [ 456.612370] Suspending console(s)
>> Feb 24 14:00:20 alekhine kernel: [ 456.616254] sd 3:0:0:0: [sda] Synchronizing SCSI cache
>> Feb 24 14:00:20 alekhine kernel: [ 456.616521] sd 3:0:0:0: [sda] Stopping disk
>> Feb 24 14:00:20 alekhine kernel: [ 456.618221] ACPI: PCI interrupt for device 0000:00:11.5 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.630296] ACPI: PCI interrupt for device 0000:00:10.4 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.641085] ACPI: PCI interrupt for device 0000:00:10.3 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.651877] ACPI: PCI interrupt for device 0000:00:10.2 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.662716] ACPI: PCI interrupt for device 0000:00:10.1 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.673550] ACPI: PCI interrupt for device 0000:00:10.0 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.684385] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.695056] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] 5 locks held by bash/2929:
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] irq event stamp: 19374
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01177c7>] __schedule_bug+0x58/0x5f
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0325b43>] schedule+0x67/0x3b3
>
> Well, could you check what's at schedule+0x67, please?
Is this how I would do this? I tried schedule+0x67, but it just showed me the beginning of profile_hit.
(gdb) l *(schedule+0x66)
0xc0325b42 is in schedule (kernel/sched.c:3836).
3831 * Test if we are atomic. Since do_exit() needs to call into
3832 * schedule() atomically, we ignore that path for now.
3833 * Otherwise, whine if we are scheduling when we should not be.
3834 */
3835 if (unlikely(in_atomic_preempt_off()) && unlikely(!prev->exit_state))
3836 __schedule_bug(prev);
3837
3838 profile_hit(SCHED_PROFILING, __builtin_return_address(0));
3839
3840 schedstat_inc(this_rq(), sched_count);
It appears that we are scheduling when we should not be...
>
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c39>] ? __mod_timer+0x8d/0x98
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326043>] schedule_timeout+0x73/0x91
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c012185c>] ? process_timeout+0x0/0xa
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c54>] msleep+0x10/0x16
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e0e51>] pci_set_power_state+0x17f/0x200
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0244917>] velocity_suspend+0x2e9/0x302
>
> velocity_suspend() seems to be at fault.
(gdb) l *(velocity_suspend+0x37)
0xc0244665 is in velocity_suspend (drivers/net/via-velocity.c:3399).
3394 if(!netif_running(vptr->dev))
3395 return 0;
3396
3397 netif_device_detach(vptr->dev);
3398
3399 spin_lock_irqsave(&vptr->lock, flags);
3400 pci_save_state(pdev);
3401 #ifdef ETHTOOL_GWOL
3402 if (vptr->flags & VELOCITY_FLAGS_WOL_ENABLED) {
3403 velocity_get_ip(vptr);
(gdb)
3404 velocity_save_context(vptr, &vptr->context);
3405 velocity_shutdown(vptr);
3406 velocity_set_wol(vptr);
3407 pci_enable_wake(pdev, PCI_D3hot, 1);
3408 pci_set_power_state(pdev, PCI_D3hot);
3409 } else {
3410 velocity_save_context(vptr, &vptr->context);
3411 velocity_shutdown(vptr);
3412 pci_disable_device(pdev);
3413 pci_set_power_state(pdev, pci_choose_state(pdev, state));
(gdb)
3414 }
3415 #else
3416 pci_set_power_state(pdev, pci_choose_state(pdev, state));
3417 #endif
3418 spin_unlock_irqrestore(&vptr->lock, flags);
3419 return 0;
3420 }
So velocity_suspend calls spin_lock_irqsave, and then pci_set_power_state which msleep()s. Is that the root problem here? (I've added Ingo & Peter to the CC list since they may have some comments on the scheduler/lockdep parts of the trace).
>
> At the moment I have to take care of some more urgent things, I'll have a look
> at it tomorrow.
>
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0133854>] ? mark_held_locks+0x4e/0x66
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e249e>] pci_device_suspend+0x1b/0x4b
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c023c625>] device_suspend+0x192/0x251
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c1c>] enter_state+0xb2/0x100
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138cfe>] state_store+0x94/0xac
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0138c6a>] ? state_store+0x0/0xac
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01d50c5>] kobj_attr_store+0x1a/0x22
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c018969f>] sysfs_write_file+0xb8/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01597d7>] vfs_write+0x88/0xf8
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0159c6e>] sys_write+0x3b/0x60
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] =======================
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732]
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] =================================
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [ INFO: inconsistent lock state ]
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] 2.6.25-rc2-next-20080224 #58
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] ---------------------------------
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] bash/2929 [HC0[0]:SC0[0]:HE1:SE1] takes:
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] {in-hardirq-W} state was registered at:
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c013416b>] __lock_acquire+0x3ac/0xb43
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0134963>] lock_acquire+0x61/0x7d
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c03279fb>] _spin_lock+0x23/0x32
>> Feb 24 14:00:20 alekhine kernel: [ 456.716732] [<c0243940>] velocity_intr+0x24/0x579
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0243940>] velocity_intr+0x24/0x579
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c02ca5e1>] snd_via8233_interrupt+0xdc/0xe7
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a884>] handle_fasteoi_irq+0x95/0xab
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01398b3>] handle_IRQ_event+0x1a/0x46
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a88d>] handle_fasteoi_irq+0x9e/0xab
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013a7ef>] handle_fasteoi_irq+0x0/0xab
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0105010>] do_IRQ+0xab/0xd4
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<ffffffff>] 0xffffffff
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] irq event stamp: 19374
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733]
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] other info that might help us debug this:
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] 5 locks held by bash/2929:
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733]
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] stack backtrace:
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0132d3b>] print_usage_bug+0x10d/0x11a
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c013361f>] mark_lock+0x1f1/0x3d8
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] mark_held_locks+0x4e/0x66
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] ? _spin_unlock_irq+0x22/0x42
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339c7>] trace_hardirqs_on+0xcf/0x120
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0327ec3>] _spin_unlock_irq+0x22/0x42
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0117322>] finish_task_switch+0x46/0x7d
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01172dc>] ? finish_task_switch+0x0/0x7d
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0325e39>] schedule+0x35d/0x3b3
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c39>] ? __mod_timer+0x8d/0x98
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326043>] schedule_timeout+0x73/0x91
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c012185c>] ? process_timeout+0x0/0xa
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0121c54>] msleep+0x10/0x16
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e0e51>] pci_set_power_state+0x17f/0x200
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0244917>] velocity_suspend+0x2e9/0x302
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0133854>] ? mark_held_locks+0x4e/0x66
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0326664>] ? __mutex_unlock_slowpath+0xd5/0xef
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01339dd>] ? trace_hardirqs_on+0xe5/0x120
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01e249e>] pci_device_suspend+0x1b/0x4b
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c023c625>] device_suspend+0x192/0x251
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138a7a>] suspend_devices_and_enter+0x3d/0xe0
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c1c>] enter_state+0xb2/0x100
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138cfe>] state_store+0x94/0xac
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0138c6a>] ? state_store+0x0/0xac
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01d50c5>] kobj_attr_store+0x1a/0x22
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c018969f>] sysfs_write_file+0xb8/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01895e7>] ? sysfs_write_file+0x0/0xe3
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c01597d7>] vfs_write+0x88/0xf8
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0159c6e>] sys_write+0x3b/0x60
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] [<c0102bfa>] sysenter_past_esp+0x5f/0xa5
>> Feb 24 14:00:20 alekhine kernel: [ 456.716733] =======================
>> Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check architecture supported.
>> Feb 24 14:00:20 alekhine kernel: [ 456.729170] Intel machine check reporting enabled on CPU#0.
>> Feb 24 14:00:20 alekhine kernel: [ 456.733181] Velocity is AUTO mode
>> Feb 24 14:00:20 alekhine kernel: [ 456.733182] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 24 14:00:20 alekhine kernel: [ 456.733184] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 24 14:00:20 alekhine kernel: [ 456.733185] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 24 14:00:20 alekhine kernel: [ 456.733185] usb usb2: root hub lost power or was reset
>> Feb 24 14:00:20 alekhine kernel: [ 456.744080] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 24 14:00:20 alekhine kernel: [ 456.744080] usb usb3: root hub lost power or was reset
>> Feb 24 14:00:20 alekhine kernel: [ 456.754997] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 24 14:00:20 alekhine kernel: [ 456.754997] usb usb4: root hub lost power or was reset
>> Feb 24 14:00:20 alekhine kernel: [ 456.765914] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 24 14:00:20 alekhine kernel: [ 456.765914] usb usb5: root hub lost power or was reset
>> Feb 24 14:00:20 alekhine kernel: [ 456.776818] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
>> Feb 24 14:00:20 alekhine kernel: [ 456.787745] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
>> Feb 24 14:00:20 alekhine kernel: [ 456.789881] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
>> Feb 24 14:00:20 alekhine kernel: [ 456.789961] sd 3:0:0:0: [sda] Starting disk
>> Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 457.031803] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 457.185224] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 457.340841] ata3.00: configured for UDMA/33
>> Feb 24 14:00:20 alekhine kernel: [ 457.528347] ata3.01: configured for UDMA/33
>> Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 460.975795] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
>> Feb 24 14:00:20 alekhine kernel: [ 460.978040] ata4.00: configured for UDMA/100
>> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
>> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write Protect is off
>> Feb 24 14:00:20 alekhine kernel: [ 460.981191] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> Feb 24 14:00:20 alekhine kernel: [ 461.524370] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
>> Feb 24 14:00:20 alekhine kernel: [ 461.569374] done.
>> Feb 24 14:00:21 alekhine kernel: [ 461.755858] usb 2-1: new low speed USB device using uhci_hcd and address 4
>> Feb 24 14:00:21 alekhine kernel: [ 461.915256] usb 2-1: configuration #1 chosen from 1 choice
>> Feb 24 14:00:21 alekhine kernel: [ 461.955599] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
>> Feb 24 14:00:21 alekhine kernel: [ 461.979344] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
>> Feb 24 14:00:21 alekhine kernel: [ 461.979553] usb 2-2: USB disconnect, address 3
>> Feb 24 14:00:21 alekhine kernel: [ 462.236114] usb 2-2: new low speed USB device using uhci_hcd and address 5
>> Feb 24 14:00:21 alekhine kernel: [ 462.405538] usb 2-2: configuration #1 chosen from 1 choice
>> Feb 24 14:00:21 alekhine kernel: [ 462.439929] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
>> Feb 24 14:00:21 alekhine kernel: [ 462.463834] input: USB HID v1.11 Keyboard [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>> Feb 24 14:00:21 alekhine kernel: [ 462.492181] input: Microsoft Microsoft? Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
>> Feb 24 14:00:21 alekhine kernel: [ 462.517592] input: USB HID v1.11 Device [Microsoft Microsoft? Digital Media Pro Keyboard] on usb-0000:00:10.0-2
On Monday, 25 of February 2008, Kevin Winchester wrote:
> Rafael J. Wysocki wrote:
> > On Sunday, 24 of February 2008, Kevin Winchester wrote:
> >
> >> Today was different - I attempted to suspend and resume from the console,
> >> and the machine did not come back up. I found the following in my log -
> >> any help would be appreciated.
> >>
> >> Feb 24 13:59:56 alekhine kernel: [ 456.497875] PM: Syncing filesystems ... done.
> >> Feb 24 14:00:20 alekhine kernel: [ 456.507273] Freezing user space processes ... (elapsed 0.00 seconds) done.
> >> Feb 24 14:00:20 alekhine kernel: [ 456.510447] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> >> Feb 24 14:00:20 alekhine kernel: [ 456.510754] ACPI: Preparing to enter system sleep state S3
> >> Feb 24 14:00:20 alekhine kernel: [ 456.612370] Suspending console(s)
> >> Feb 24 14:00:20 alekhine kernel: [ 456.616254] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> >> Feb 24 14:00:20 alekhine kernel: [ 456.616521] sd 3:0:0:0: [sda] Stopping disk
> >> Feb 24 14:00:20 alekhine kernel: [ 456.618221] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.630296] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.641085] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.651877] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.662716] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.673550] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.684385] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.695056] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] 5 locks held by bash/2929:
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] irq event stamp: 19374
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01177c7>] __schedule_bug+0x58/0x5f
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0325b43>] schedule+0x67/0x3b3
> >
> > Well, could you check what's at schedule+0x67, please?
>
> Is this how I would do this? I tried schedule+0x67, but it just showed me the beginning of profile_hit.
>
> (gdb) l *(schedule+0x66)
> 0xc0325b42 is in schedule (kernel/sched.c:3836).
> 3831 * Test if we are atomic. Since do_exit() needs to call into
> 3832 * schedule() atomically, we ignore that path for now.
> 3833 * Otherwise, whine if we are scheduling when we should not be.
> 3834 */
> 3835 if (unlikely(in_atomic_preempt_off()) && unlikely(!prev->exit_state))
> 3836 __schedule_bug(prev);
> 3837
> 3838 profile_hit(SCHED_PROFILING, __builtin_return_address(0));
> 3839
> 3840 schedstat_inc(this_rq(), sched_count);
>
> It appears that we are scheduling when we should not be...
>
>
> >
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c39>] ? __mod_timer+0x8d/0x98
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326043>] schedule_timeout+0x73/0x91
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c012185c>] ? process_timeout+0x0/0xa
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c54>] msleep+0x10/0x16
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e0e51>] pci_set_power_state+0x17f/0x200
> >> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0244917>] velocity_suspend+0x2e9/0x302
> >
> > velocity_suspend() seems to be at fault.
>
> (gdb) l *(velocity_suspend+0x37)
> 0xc0244665 is in velocity_suspend (drivers/net/via-velocity.c:3399).
> 3394 if(!netif_running(vptr->dev))
> 3395 return 0;
> 3396
> 3397 netif_device_detach(vptr->dev);
> 3398
> 3399 spin_lock_irqsave(&vptr->lock, flags);
> 3400 pci_save_state(pdev);
> 3401 #ifdef ETHTOOL_GWOL
> 3402 if (vptr->flags & VELOCITY_FLAGS_WOL_ENABLED) {
> 3403 velocity_get_ip(vptr);
> (gdb)
> 3404 velocity_save_context(vptr, &vptr->context);
> 3405 velocity_shutdown(vptr);
> 3406 velocity_set_wol(vptr);
> 3407 pci_enable_wake(pdev, PCI_D3hot, 1);
> 3408 pci_set_power_state(pdev, PCI_D3hot);
Hm, why doesn't it use pci_choose_state() here?
> 3409 } else {
> 3410 velocity_save_context(vptr, &vptr->context);
> 3411 velocity_shutdown(vptr);
> 3412 pci_disable_device(pdev);
> 3413 pci_set_power_state(pdev, pci_choose_state(pdev, state));
> (gdb)
> 3414 }
> 3415 #else
> 3416 pci_set_power_state(pdev, pci_choose_state(pdev, state));
> 3417 #endif
> 3418 spin_unlock_irqrestore(&vptr->lock, flags);
> 3419 return 0;
> 3420 }
>
> So velocity_suspend calls spin_lock_irqsave, and then pci_set_power_state
> which msleep()s. Is that the root problem here?
Yes, most probably, it is.
> (I've added Ingo & Peter to the CC list since they may have some comments on
> the scheduler/lockdep parts of the trace).
Well, it calls many things it shouldn't call under a spinlock, AFAICS.
Who's maintaining this driver?
Rafael
Rafael J. Wysocki wrote:
> On Monday, 25 of February 2008, Kevin Winchester wrote:
>> Rafael J. Wysocki wrote:
>>> On Sunday, 24 of February 2008, Kevin Winchester wrote:
>>>
>>>> Today was different - I attempted to suspend and resume from the console,
>>>> and the machine did not come back up. I found the following in my log -
>>>> any help would be appreciated.
>>>>
>>>> Feb 24 13:59:56 alekhine kernel: [ 456.497875] PM: Syncing filesystems ... done.
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.507273] Freezing user space processes ... (elapsed 0.00 seconds) done.
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.510447] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.510754] ACPI: Preparing to enter system sleep state S3
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.612370] Suspending console(s)
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.616254] sd 3:0:0:0: [sda] Synchronizing SCSI cache
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.616521] sd 3:0:0:0: [sda] Stopping disk
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.618221] ACPI: PCI interrupt for device 0000:00:11.5 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.630296] ACPI: PCI interrupt for device 0000:00:10.4 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.641085] ACPI: PCI interrupt for device 0000:00:10.3 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.651877] ACPI: PCI interrupt for device 0000:00:10.2 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.662716] ACPI: PCI interrupt for device 0000:00:10.1 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.673550] ACPI: PCI interrupt for device 0000:00:10.0 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.684385] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.695056] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] 5 locks held by bash/2929:
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #0: (&buffer->mutex){--..}, at: [<c018960c>] sysfs_write_file+0x25/0xe3
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #1: (pm_mutex){--..}, at: [<c0138c54>] enter_state+0xea/0x100
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #2: (pm_sleep_rwsem){----}, at: [<c023c4b8>] device_suspend+0x25/0x251
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #3: (&data->update_lock#2){--..}, at: [<c029cb2b>] abituguru_suspend+0x13/0x18
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] #4: (&vptr->lock){++..}, at: [<c0244665>] velocity_suspend+0x37/0x302
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] irq event stamp: 19374
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last enabled at (19373): [<c0326664>] __mutex_unlock_slowpath+0xd5/0xef
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] hardirqs last disabled at (19374): [<c0327bca>] _spin_lock_irqsave+0xf/0x3c
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last enabled at (18484): [<c011e6ba>] __do_softirq+0x99/0x9e
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] softirqs last disabled at (18479): [<c0104f15>] do_softirq+0x58/0xa8
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] Pid: 2929, comm: bash Not tainted 2.6.25-rc2-next-20080224 #58
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01177c7>] __schedule_bug+0x58/0x5f
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0325b43>] schedule+0x67/0x3b3
>>> Well, could you check what's at schedule+0x67, please?
>> Is this how I would do this? I tried schedule+0x67, but it just showed me the beginning of profile_hit.
>>
>> (gdb) l *(schedule+0x66)
>> 0xc0325b42 is in schedule (kernel/sched.c:3836).
>> 3831 * Test if we are atomic. Since do_exit() needs to call into
>> 3832 * schedule() atomically, we ignore that path for now.
>> 3833 * Otherwise, whine if we are scheduling when we should not be.
>> 3834 */
>> 3835 if (unlikely(in_atomic_preempt_off()) && unlikely(!prev->exit_state))
>> 3836 __schedule_bug(prev);
>> 3837
>> 3838 profile_hit(SCHED_PROFILING, __builtin_return_address(0));
>> 3839
>> 3840 schedstat_inc(this_rq(), sched_count);
>>
>> It appears that we are scheduling when we should not be...
>>
>>
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c39>] ? __mod_timer+0x8d/0x98
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326043>] schedule_timeout+0x73/0x91
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c012185c>] ? process_timeout+0x0/0xa
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0326075>] schedule_timeout_uninterruptible+0x14/0x16
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0121c54>] msleep+0x10/0x16
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c01e0e51>] pci_set_power_state+0x17f/0x200
>>>> Feb 24 14:00:20 alekhine kernel: [ 456.705856] [<c0244917>] velocity_suspend+0x2e9/0x302
>>> velocity_suspend() seems to be at fault.
>> (gdb) l *(velocity_suspend+0x37)
>> 0xc0244665 is in velocity_suspend (drivers/net/via-velocity.c:3399).
>> 3394 if(!netif_running(vptr->dev))
>> 3395 return 0;
>> 3396
>> 3397 netif_device_detach(vptr->dev);
>> 3398
>> 3399 spin_lock_irqsave(&vptr->lock, flags);
>> 3400 pci_save_state(pdev);
>> 3401 #ifdef ETHTOOL_GWOL
>> 3402 if (vptr->flags & VELOCITY_FLAGS_WOL_ENABLED) {
>> 3403 velocity_get_ip(vptr);
>> (gdb)
>> 3404 velocity_save_context(vptr, &vptr->context);
>> 3405 velocity_shutdown(vptr);
>> 3406 velocity_set_wol(vptr);
>> 3407 pci_enable_wake(pdev, PCI_D3hot, 1);
>> 3408 pci_set_power_state(pdev, PCI_D3hot);
>
> Hm, why doesn't it use pci_choose_state() here?
>
>> 3409 } else {
>> 3410 velocity_save_context(vptr, &vptr->context);
>> 3411 velocity_shutdown(vptr);
>> 3412 pci_disable_device(pdev);
>> 3413 pci_set_power_state(pdev, pci_choose_state(pdev, state));
>> (gdb)
>> 3414 }
>> 3415 #else
>> 3416 pci_set_power_state(pdev, pci_choose_state(pdev, state));
>> 3417 #endif
>> 3418 spin_unlock_irqrestore(&vptr->lock, flags);
>> 3419 return 0;
>> 3420 }
>>
>> So velocity_suspend calls spin_lock_irqsave, and then pci_set_power_state
>> which msleep()s. Is that the root problem here?
>
> Yes, most probably, it is.
>
>> (I've added Ingo & Peter to the CC list since they may have some comments on
>> the scheduler/lockdep parts of the trace).
>
> Well, it calls many things it shouldn't call under a spinlock, AFAICS.
>
> Who's maintaining this driver?
>
Added:
VIA VELOCITY NETWORK DRIVER
P: Francois Romieu
M: [email protected]
L: [email protected]
S: Maintained
Hi!
> > velocity_suspend() seems to be at fault.
>
> (gdb) l *(velocity_suspend+0x37)
> 0xc0244665 is in velocity_suspend (drivers/net/via-velocity.c:3399).
> 3394 if(!netif_running(vptr->dev))
> 3395 return 0;
> 3396
> 3397 netif_device_detach(vptr->dev);
> 3398
> 3399 spin_lock_irqsave(&vptr->lock, flags);
> 3400 pci_save_state(pdev);
> 3401 #ifdef ETHTOOL_GWOL
> 3402 if (vptr->flags & VELOCITY_FLAGS_WOL_ENABLED) {
> 3403 velocity_get_ip(vptr);
> (gdb)
> 3404 velocity_save_context(vptr, &vptr->context);
> 3405 velocity_shutdown(vptr);
> 3406 velocity_set_wol(vptr);
> 3407 pci_enable_wake(pdev, PCI_D3hot, 1);
> 3408 pci_set_power_state(pdev, PCI_D3hot);
> 3409 } else {
> 3410 velocity_save_context(vptr, &vptr->context);
> 3411 velocity_shutdown(vptr);
> 3412 pci_disable_device(pdev);
> 3413 pci_set_power_state(pdev, pci_choose_state(pdev, state));
> (gdb)
> 3414 }
> 3415 #else
> 3416 pci_set_power_state(pdev, pci_choose_state(pdev, state));
> 3417 #endif
> 3418 spin_unlock_irqrestore(&vptr->lock, flags);
> 3419 return 0;
> 3420 }
>
> So velocity_suspend calls spin_lock_irqsave, and then pci_set_power_state which msleep()s. Is that the root problem here? (I've added Ingo & Peter to the CC list since they may have some comments on the scheduler/lockdep parts of the trace).
Looks like velocity is broken. Can you try to unload it before sleep
to see if the rest of suspend works for you?
--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
On Sun, 24 Feb 2008, Stephen Rothwell wrote:
> I have created today's linux-next tree at
> git://git.kernel.org/pub/scm/linux/kernel/git/sfr/linux-next.git.
>
> You can see which trees have been included by looking in the Next/Trees
> file in the source. There are also quilt-import.log and merge.log files
> in the Next directory. Between each merge, the tree was built with
> allmodconfig for both powerpc and x86_64.
>
> There only one minor merge problem and a few build failures (the two in
> Linus' tree have been fixed and the other reported).
>
> We are up to 32 trees, more are welcome (even if they are currently
> empty).
Can you please add
http://linux-m68k-cvs.ubb.ca/~geert/linux-m68k-patches-2.6/series?
So far there's only one patch in between NEXT_PATCHES_{START,END} yet,
though.
> Status of my local build tests is at
> http://kisskb.ellerman.id.au/kisskb/branch/9/.
Ah, I see the m68k cross-compiler is still missing? ;-)
Gr{oetje,eeting}s,
Geert
P.S. For the interested, a script to update the SHA1 in the quilt series file:
anakin$ cat $(type -p quilt-update-git-base)
#!/bin/bash
series=patches/series
if [ ! -f $series ]; then
echo Cannot find $series
exit 1
fi
if head=$(git rev-parse --verify HEAD); then
if grep '^# BASE' $series > /dev/null; then
sed -i -e "s/^# BASE.*$/# BASE $head/" $series
echo Updated BASE to $head
else
echo No BASE found
fi
fi
anakin$
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds
On Mon, 25 Feb 2008 22:56:04 +0100 (CET) Geert Uytterhoeven wrote:
> P.S. For the interested, a script to update the SHA1 in the quilt series file:
Thanks, anakin.
Version to update $BASE based on current kernel tree is attached.
---
~Randy
Hi Geert,
On Mon, 25 Feb 2008 22:56:04 +0100 (CET) Geert Uytterhoeven <[email protected]> wrote:
>
> Can you please add
> http://linux-m68k-cvs.ubb.ca/~geert/linux-m68k-patches-2.6/series?
> So far there's only one patch in between NEXT_PATCHES_{START,END} yet,
> though.
Added, thanks.
> Ah, I see the m68k cross-compiler is still missing? ;-)
Please look again :-) Are there any particular configs we should build?
--
Cheers,
Stephen Rothwell [email protected]
http://www.canb.auug.org.au/~sfr/
Pavel Machek wrote:
> Hi!
>
>>> velocity_suspend() seems to be at fault.
>> (gdb) l *(velocity_suspend+0x37)
>> 0xc0244665 is in velocity_suspend (drivers/net/via-velocity.c:3399).
>> 3394 if(!netif_running(vptr->dev))
>> 3395 return 0;
>> 3396
>> 3397 netif_device_detach(vptr->dev);
>> 3398
>> 3399 spin_lock_irqsave(&vptr->lock, flags);
>> 3400 pci_save_state(pdev);
>> 3401 #ifdef ETHTOOL_GWOL
>> 3402 if (vptr->flags & VELOCITY_FLAGS_WOL_ENABLED) {
>> 3403 velocity_get_ip(vptr);
>> (gdb)
>> 3404 velocity_save_context(vptr, &vptr->context);
>> 3405 velocity_shutdown(vptr);
>> 3406 velocity_set_wol(vptr);
>> 3407 pci_enable_wake(pdev, PCI_D3hot, 1);
>> 3408 pci_set_power_state(pdev, PCI_D3hot);
>> 3409 } else {
>> 3410 velocity_save_context(vptr, &vptr->context);
>> 3411 velocity_shutdown(vptr);
>> 3412 pci_disable_device(pdev);
>> 3413 pci_set_power_state(pdev, pci_choose_state(pdev, state));
>> (gdb)
>> 3414 }
>> 3415 #else
>> 3416 pci_set_power_state(pdev, pci_choose_state(pdev, state));
>> 3417 #endif
>> 3418 spin_unlock_irqrestore(&vptr->lock, flags);
>> 3419 return 0;
>> 3420 }
>>
>> So velocity_suspend calls spin_lock_irqsave, and then pci_set_power_state which msleep()s. Is that the root problem here? (I've added Ingo & Peter to the CC list since they may have some comments on the scheduler/lockdep parts of the trace).
>
> Looks like velocity is broken. Can you try to unload it before sleep
> to see if the rest of suspend works for you?
>
(Trimmed cc, since this is really just more of a PM discussion)
No modules here...
I recompiled the kernel without the velocity driver, and got behaviour more comparable to the other failures I've experienced in the past:
Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
I don't see anything there that would explain the failure, but the console never comes back, and I am forced to hard reset the box. Anything else I can try?
Thanks,
--
Kevin Winchester
On Tuesday, 26 of February 2008, Kevin Winchester wrote:
> Pavel Machek wrote:
[--snip--]
> (Trimmed cc, since this is really just more of a PM discussion)
>
> No modules here...
>
> I recompiled the kernel without the velocity driver, and got behaviour more
> comparable to the other failures I've experienced in the past:
>
> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>
>
> I don't see anything there that would explain the failure, but the console
> never comes back, and I am forced to hard reset the box. Anything else I can
> try?
First, let's try to remove some noise.
Please test 2.6.25-rc3 with commit 559bbe6cbd0d8c68d40076a5f7dc98e3bf5864b2
"power_state: get rid of write-only variable in SATA" reverted and with the
patch from http://marc.info/?l=linux-acpi&m=120389632114090&w=2 applied.
Second, what exactly do you do to suspend to RAM?
Rafael
On Tue, 26 Feb 2008, Stephen Rothwell wrote:
> On Mon, 25 Feb 2008 22:56:04 +0100 (CET) Geert Uytterhoeven <[email protected]> wrote:
> >
> > Can you please add
> > http://linux-m68k-cvs.ubb.ca/~geert/linux-m68k-patches-2.6/series?
> > So far there's only one patch in between NEXT_PATCHES_{START,END} yet,
> > though.
>
> Added, thanks.
>
> > Ah, I see the m68k cross-compiler is still missing? ;-)
>
> Please look again :-) Are there any particular configs we should build?
Great!
I really should update the defconfigs, and add a `defconfig_all' which
builds a kernel for all platforms (except Sun-3).
For now defconfig is OK, I think.
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds
Hi!
> I recompiled the kernel without the velocity driver, and got behaviour more comparable to the other failures I've experienced in the past:
>
> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>
>
> I don't see anything there that would explain the failure, but the console never comes back, and I am forced to hard reset the box. Anything else I can try?
>
So machine works but video is that? See suspend.sf.net...
--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
Pavel Machek wrote:
> Hi!
>
>> I recompiled the kernel without the velocity driver, and got behaviour more comparable to the other failures I've experienced in the past:
>>
>> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
>> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
>> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
>> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
>> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
>> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
>> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
>> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
>> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
>> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
>> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
>> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
>> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
>> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
>> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
>> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
>> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
>> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
>> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
>> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
>> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
>> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
>> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>>
>>
>> I don't see anything there that would explain the failure, but the console never comes back, and I am forced to hard reset the box. Anything else I can try?
>>
>
> So machine works but video is that? See suspend.sf.net...
>
I haven't done too much looking at what the tool on that site does,
but I was under the impression that I should be able to do:
echo mem > /sys/power/state
and then bring the system back up and have it work. If that is
not expected to work, then I won't bother trying it again. My
goal in all this is to help test the kernel, and provide feedback
and testing for features that are expected to work. If this is
expected to work, then I would rather provide testing for patches
to the kernel that will make this work, rather than relying on
userspace tricks to get around a broken kernel (because frankly,
I couldn't care much less if STR works for me or not - I was just
testing it to be helpful).
Am I wrong about this? Is the tool at suspend.sf.net supposed to
be required for STR to work with current linux kernels?
--
Kevin Winchester
Rafael J. Wysocki wrote:
> On Tuesday, 26 of February 2008, Kevin Winchester wrote:
>> Pavel Machek wrote:
> [--snip--]
>> (Trimmed cc, since this is really just more of a PM discussion)
>>
>> No modules here...
>>
>> I recompiled the kernel without the velocity driver, and got behaviour more
>> comparable to the other failures I've experienced in the past:
>>
>> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
>> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
>> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
>> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
>> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
>> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
>> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
>> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
>> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
>> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
>> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
>> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
>> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
>> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
>> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
>> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
>> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
>> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
>> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
>> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
>> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
>> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
>> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
>> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
>> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
>> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
>> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
>> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
>> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
>> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>>
>>
>> I don't see anything there that would explain the failure, but the console
>> never comes back, and I am forced to hard reset the box. Anything else I can
>> try?
>
> First, let's try to remove some noise.
>
> Please test 2.6.25-rc3 with commit 559bbe6cbd0d8c68d40076a5f7dc98e3bf5864b2
> "power_state: get rid of write-only variable in SATA" reverted and with the
> patch from http://marc.info/?l=linux-acpi&m=120389632114090&w=2 applied.
>
> Second, what exactly do you do to suspend to RAM?
>
To suspend to ram, I do Ctrl-Alt-1 to switch from the GDM login screen to
the console, and then:
/etc/init.d/gdm stop
echo mem > /sys/power/state
I have also tried it from X in the past (using the Ubuntu quit menu option),
with just about the same result, as I recall. This time I figured I would
try to make it easier for the suspend code and try it from the console.
Should I have been doing something else?
--
Kevin Winchester
Rafael J. Wysocki wrote:
> On Tuesday, 26 of February 2008, Kevin Winchester wrote:
>> Pavel Machek wrote:
> [--snip--]
>> (Trimmed cc, since this is really just more of a PM discussion)
>>
>> No modules here...
>>
>> I recompiled the kernel without the velocity driver, and got behaviour more
>> comparable to the other failures I've experienced in the past:
>>
<snip old trace>
>>
>>
>> I don't see anything there that would explain the failure, but the console
>> never comes back, and I am forced to hard reset the box. Anything else I can
>> try?
>
> First, let's try to remove some noise.
>
> Please test 2.6.25-rc3 with commit 559bbe6cbd0d8c68d40076a5f7dc98e3bf5864b2
> "power_state: get rid of write-only variable in SATA" reverted and with the
> patch from http://marc.info/?l=linux-acpi&m=120389632114090&w=2 applied.
>
> Second, what exactly do you do to suspend to RAM?
>
And here is the trace from the kernel with the revert and patch:
Feb 26 20:42:14 alekhine kernel: [ 278.487844] PM: Syncing filesystems ... done.
Feb 26 20:42:40 alekhine kernel: [ 278.523599] Freezing user space processes ... (elapsed 0.00 seconds) done.
Feb 26 20:42:40 alekhine kernel: [ 278.525885] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
Feb 26 20:42:40 alekhine kernel: [ 278.526196] ACPI: Preparing to enter system sleep state S3
Feb 26 20:42:40 alekhine kernel: [ 278.627907] Suspending console(s)
Feb 26 20:42:40 alekhine kernel: [ 278.631643] sd 3:0:0:0: [sda] Synchronizing SCSI cache
Feb 26 20:42:40 alekhine kernel: [ 278.738062] sd 3:0:0:0: [sda] Stopping disk
Feb 26 20:42:40 alekhine kernel: [ 278.739041] ACPI: PCI interrupt for device 0000:00:11.5 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.749597] ACPI: PCI interrupt for device 0000:00:10.4 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.760383] ACPI: PCI interrupt for device 0000:00:10.3 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.771183] ACPI: PCI interrupt for device 0000:00:10.2 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.782017] ACPI: PCI interrupt for device 0000:00:10.1 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.792851] ACPI: PCI interrupt for device 0000:00:10.0 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.803686] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.814329] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
Feb 26 20:42:40 alekhine kernel: [ 278.837854] Intel machine check architecture supported.
Feb 26 20:42:40 alekhine kernel: [ 278.837854] Intel machine check reporting enabled on CPU#0.
Feb 26 20:42:40 alekhine kernel: [ 278.840865] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 26 20:42:40 alekhine kernel: [ 278.840866] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
Feb 26 20:42:40 alekhine kernel: [ 278.846866] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
Feb 26 20:42:40 alekhine kernel: [ 278.846866] usb usb2: root hub lost power or was reset
Feb 26 20:42:40 alekhine kernel: [ 278.857689] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
Feb 26 20:42:40 alekhine kernel: [ 278.857689] usb usb3: root hub lost power or was reset
Feb 26 20:42:40 alekhine kernel: [ 278.868560] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
Feb 26 20:42:40 alekhine kernel: [ 278.868560] usb usb4: root hub lost power or was reset
Feb 26 20:42:40 alekhine kernel: [ 278.879436] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
Feb 26 20:42:40 alekhine kernel: [ 278.879436] usb usb5: root hub lost power or was reset
Feb 26 20:42:40 alekhine kernel: [ 278.890311] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
Feb 26 20:42:40 alekhine kernel: [ 278.901173] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
Feb 26 20:42:40 alekhine kernel: [ 278.903446] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
Feb 26 20:42:40 alekhine kernel: [ 278.903642] sd 3:0:0:0: [sda] Starting disk
Feb 26 20:42:40 alekhine kernel: [ 279.144623] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 279.144623] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 279.297860] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 279.297860] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 279.453232] ata3.00: configured for UDMA/33
Feb 26 20:42:40 alekhine kernel: [ 279.640338] ata3.01: configured for UDMA/33
Feb 26 20:42:40 alekhine kernel: [ 283.485517] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 283.485517] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
Feb 26 20:42:40 alekhine kernel: [ 283.487637] ata4.00: configured for UDMA/100
Feb 26 20:42:40 alekhine kernel: [ 283.490010] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
Feb 26 20:42:40 alekhine kernel: [ 283.490030] sd 3:0:0:0: [sda] Write Protect is off
Feb 26 20:42:40 alekhine kernel: [ 283.490137] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 26 20:42:40 alekhine kernel: [ 284.034036] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
Feb 26 20:42:40 alekhine kernel: [ 284.061980] done.
Feb 26 20:42:40 alekhine kernel: [ 284.265037] usb 2-1: new low speed USB device using uhci_hcd and address 4
Feb 26 20:42:40 alekhine kernel: [ 284.428562] usb 2-1: configuration #1 chosen from 1 choice
Feb 26 20:42:40 alekhine kernel: [ 284.452701] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
Feb 26 20:42:40 alekhine kernel: [ 284.495532] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
Feb 26 20:42:40 alekhine kernel: [ 284.495724] usb 2-2: USB disconnect, address 3
Feb 26 20:42:40 alekhine kernel: [ 284.751242] usb 2-2: new low speed USB device using uhci_hcd and address 5
Feb 26 20:42:41 alekhine kernel: [ 284.920833] usb 2-2: configuration #1 chosen from 1 choice
Feb 26 20:42:41 alekhine kernel: [ 284.938005] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
Feb 26 20:42:41 alekhine kernel: [ 284.977818] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
Feb 26 20:42:41 alekhine kernel: [ 285.012253] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
Feb 26 20:42:41 alekhine kernel: [ 285.033838] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
It looks basically identical to me, but I haven't diff'ed them or
anything. Do you have any other options, or am I out of luck for\
the moment?
Thanks for the help,
--
Kevin Winchester
On Wednesday, 27 of February 2008, Kevin Winchester wrote:
> Rafael J. Wysocki wrote:
> > On Tuesday, 26 of February 2008, Kevin Winchester wrote:
> >> Pavel Machek wrote:
> > [--snip--]
> >> (Trimmed cc, since this is really just more of a PM discussion)
> >>
> >> No modules here...
> >>
> >> I recompiled the kernel without the velocity driver, and got behaviour more
> >> comparable to the other failures I've experienced in the past:
> >>
> >> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
> >> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
> >> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> >> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
> >> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> >> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> >> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> >> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> >> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
> >> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
> >> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
> >> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> >> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> >> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
> >> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
> >> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
> >> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> >> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> >> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
> >> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
> >> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
> >> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> >> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> >> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> >> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> >>
> >>
> >> I don't see anything there that would explain the failure, but the console
> >> never comes back, and I am forced to hard reset the box. Anything else I can
> >> try?
> >
> > First, let's try to remove some noise.
> >
> > Please test 2.6.25-rc3 with commit 559bbe6cbd0d8c68d40076a5f7dc98e3bf5864b2
> > "power_state: get rid of write-only variable in SATA" reverted and with the
> > patch from http://marc.info/?l=linux-acpi&m=120389632114090&w=2 applied.
> >
> > Second, what exactly do you do to suspend to RAM?
> >
>
> To suspend to ram, I do Ctrl-Alt-1 to switch from the GDM login screen to
> the console, and then:
>
> /etc/init.d/gdm stop
> echo mem > /sys/power/state
>
> I have also tried it from X in the past (using the Ubuntu quit menu option),
> with just about the same result, as I recall. This time I figured I would
> try to make it easier for the suspend code and try it from the console.
>
> Should I have been doing something else?
You can try the s2ram program from suspend.sf.net
(http://suspend.sf.net/s2ram-support.html).
Thanks,
Rafael
On Wednesday, 27 of February 2008, Kevin Winchester wrote:
> Rafael J. Wysocki wrote:
> > On Tuesday, 26 of February 2008, Kevin Winchester wrote:
> >> Pavel Machek wrote:
> > [--snip--]
> >> (Trimmed cc, since this is really just more of a PM discussion)
> >>
> >> No modules here...
> >>
> >> I recompiled the kernel without the velocity driver, and got behaviour more
> >> comparable to the other failures I've experienced in the past:
> >>
>
> <snip old trace>
>
> >>
> >>
> >> I don't see anything there that would explain the failure, but the console
> >> never comes back, and I am forced to hard reset the box. Anything else I can
> >> try?
> >
> > First, let's try to remove some noise.
> >
> > Please test 2.6.25-rc3 with commit 559bbe6cbd0d8c68d40076a5f7dc98e3bf5864b2
> > "power_state: get rid of write-only variable in SATA" reverted and with the
> > patch from http://marc.info/?l=linux-acpi&m=120389632114090&w=2 applied.
> >
> > Second, what exactly do you do to suspend to RAM?
> >
>
> And here is the trace from the kernel with the revert and patch:
>
> Feb 26 20:42:14 alekhine kernel: [ 278.487844] PM: Syncing filesystems ... done.
> Feb 26 20:42:40 alekhine kernel: [ 278.523599] Freezing user space processes ... (elapsed 0.00 seconds) done.
> Feb 26 20:42:40 alekhine kernel: [ 278.525885] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> Feb 26 20:42:40 alekhine kernel: [ 278.526196] ACPI: Preparing to enter system sleep state S3
> Feb 26 20:42:40 alekhine kernel: [ 278.627907] Suspending console(s)
> Feb 26 20:42:40 alekhine kernel: [ 278.631643] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> Feb 26 20:42:40 alekhine kernel: [ 278.738062] sd 3:0:0:0: [sda] Stopping disk
> Feb 26 20:42:40 alekhine kernel: [ 278.739041] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.749597] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.760383] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.771183] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.782017] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.792851] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.803686] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.814329] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> Feb 26 20:42:40 alekhine kernel: [ 278.837854] Intel machine check architecture supported.
> Feb 26 20:42:40 alekhine kernel: [ 278.837854] Intel machine check reporting enabled on CPU#0.
> Feb 26 20:42:40 alekhine kernel: [ 278.840865] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 26 20:42:40 alekhine kernel: [ 278.840866] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> Feb 26 20:42:40 alekhine kernel: [ 278.846866] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 26 20:42:40 alekhine kernel: [ 278.846866] usb usb2: root hub lost power or was reset
> Feb 26 20:42:40 alekhine kernel: [ 278.857689] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> Feb 26 20:42:40 alekhine kernel: [ 278.857689] usb usb3: root hub lost power or was reset
> Feb 26 20:42:40 alekhine kernel: [ 278.868560] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 26 20:42:40 alekhine kernel: [ 278.868560] usb usb4: root hub lost power or was reset
> Feb 26 20:42:40 alekhine kernel: [ 278.879436] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> Feb 26 20:42:40 alekhine kernel: [ 278.879436] usb usb5: root hub lost power or was reset
> Feb 26 20:42:40 alekhine kernel: [ 278.890311] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> Feb 26 20:42:40 alekhine kernel: [ 278.901173] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> Feb 26 20:42:40 alekhine kernel: [ 278.903446] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> Feb 26 20:42:40 alekhine kernel: [ 278.903642] sd 3:0:0:0: [sda] Starting disk
> Feb 26 20:42:40 alekhine kernel: [ 279.144623] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 279.144623] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 279.297860] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 279.297860] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 279.453232] ata3.00: configured for UDMA/33
> Feb 26 20:42:40 alekhine kernel: [ 279.640338] ata3.01: configured for UDMA/33
> Feb 26 20:42:40 alekhine kernel: [ 283.485517] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 283.485517] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> Feb 26 20:42:40 alekhine kernel: [ 283.487637] ata4.00: configured for UDMA/100
> Feb 26 20:42:40 alekhine kernel: [ 283.490010] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> Feb 26 20:42:40 alekhine kernel: [ 283.490030] sd 3:0:0:0: [sda] Write Protect is off
> Feb 26 20:42:40 alekhine kernel: [ 283.490137] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> Feb 26 20:42:40 alekhine kernel: [ 284.034036] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> Feb 26 20:42:40 alekhine kernel: [ 284.061980] done.
> Feb 26 20:42:40 alekhine kernel: [ 284.265037] usb 2-1: new low speed USB device using uhci_hcd and address 4
> Feb 26 20:42:40 alekhine kernel: [ 284.428562] usb 2-1: configuration #1 chosen from 1 choice
> Feb 26 20:42:40 alekhine kernel: [ 284.452701] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> Feb 26 20:42:40 alekhine kernel: [ 284.495532] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> Feb 26 20:42:40 alekhine kernel: [ 284.495724] usb 2-2: USB disconnect, address 3
> Feb 26 20:42:40 alekhine kernel: [ 284.751242] usb 2-2: new low speed USB device using uhci_hcd and address 5
> Feb 26 20:42:41 alekhine kernel: [ 284.920833] usb 2-2: configuration #1 chosen from 1 choice
> Feb 26 20:42:41 alekhine kernel: [ 284.938005] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> Feb 26 20:42:41 alekhine kernel: [ 284.977818] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> Feb 26 20:42:41 alekhine kernel: [ 285.012253] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> Feb 26 20:42:41 alekhine kernel: [ 285.033838] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
>
> It looks basically identical to me, but I haven't diff'ed them or
> anything. Do you have any other options, or am I out of luck for\
> the moment?
Please try s2ram first and if that doesn't work for you, we can debug it a bit
further.
Thanks,
Rafael
On Wednesday, 27 of February 2008, Kevin Winchester wrote:
> Pavel Machek wrote:
> > Hi!
> >
> >> I recompiled the kernel without the velocity driver, and got behaviour more comparable to the other failures I've experienced in the past:
> >>
> >> Feb 25 20:18:46 alekhine kernel: [ 73.564725] PM: Syncing filesystems ... done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.580807] Freezing user space processes ... (elapsed 0.01 seconds) done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.595524] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.595839] ACPI: Preparing to enter system sleep state S3
> >> Feb 25 20:19:14 alekhine kernel: [ 73.697308] Suspending console(s)
> >> Feb 25 20:19:14 alekhine kernel: [ 73.700386] sd 3:0:0:0: [sda] Synchronizing SCSI cache
> >> Feb 25 20:19:14 alekhine kernel: [ 73.783185] sd 3:0:0:0: [sda] Stopping disk
> >> Feb 25 20:19:14 alekhine kernel: [ 73.784302] ACPI: PCI interrupt for device 0000:00:11.5 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.794585] ACPI: PCI interrupt for device 0000:00:10.4 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.805370] ACPI: PCI interrupt for device 0000:00:10.3 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.816170] ACPI: PCI interrupt for device 0000:00:10.2 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.826999] ACPI: PCI interrupt for device 0000:00:10.1 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.837833] ACPI: PCI interrupt for device 0000:00:10.0 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.848668] ACPI: PCI interrupt for device 0000:00:0f.1 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.859346] ACPI: PCI interrupt for device 0000:00:0f.0 disabled
> >> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check architecture supported.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.882878] Intel machine check reporting enabled on CPU#0.
> >> Feb 25 20:19:14 alekhine kernel: [ 73.884890] ACPI: PCI Interrupt 0000:00:0f.0[B] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> >> Feb 25 20:19:14 alekhine kernel: [ 73.884892] ACPI: PCI Interrupt 0000:00:0f.1[A] -> Link [ALKA] -> GSI 20 (level, low) -> IRQ 20
> >> Feb 25 20:19:14 alekhine kernel: [ 73.890893] ACPI: PCI Interrupt 0000:00:10.0[A] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.890893] usb usb2: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.901724] ACPI: PCI Interrupt 0000:00:10.1[A] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.901724] usb usb3: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.912597] ACPI: PCI Interrupt 0000:00:10.2[B] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.912597] usb usb4: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.923472] ACPI: PCI Interrupt 0000:00:10.3[B] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.923472] usb usb5: root hub lost power or was reset
> >> Feb 25 20:19:14 alekhine kernel: [ 73.934336] ACPI: PCI Interrupt 0000:00:10.4[C] -> GSI 21 (level, low) -> IRQ 21
> >> Feb 25 20:19:14 alekhine kernel: [ 73.945209] ACPI: PCI Interrupt 0000:00:11.5[C] -> GSI 22 (level, low) -> IRQ 22
> >> Feb 25 20:19:14 alekhine kernel: [ 73.947465] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
> >> Feb 25 20:19:14 alekhine kernel: [ 73.947660] sd 3:0:0:0: [sda] Starting disk
> >> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:0c:00:00:00:b0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.183122] ata3.01: ACPI cmd ef/03:42:00:00:00:b0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.336028] ata3.00: ACPI cmd ef/03:42:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 74.491252] ata3.00: configured for UDMA/33
> >> Feb 25 20:19:14 alekhine kernel: [ 74.678330] ata3.01: configured for UDMA/33
> >> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 78.168897] ata4.00: ACPI cmd ef/03:45:00:00:00:a0 filtered out
> >> Feb 25 20:19:14 alekhine kernel: [ 78.172976] ata4.00: configured for UDMA/100
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write Protect is off
> >> Feb 25 20:19:14 alekhine kernel: [ 78.177133] sd 3:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
> >> Feb 25 20:19:14 alekhine kernel: [ 78.720991] Restarting tasks ... <6>usb 2-1: USB disconnect, address 2
> >> Feb 25 20:19:14 alekhine kernel: [ 78.766838] done.
> >> Feb 25 20:19:14 alekhine kernel: [ 78.951998] usb 2-1: new low speed USB device using uhci_hcd and address 4
> >> Feb 25 20:19:14 alekhine kernel: [ 79.114037] usb 2-1: configuration #1 chosen from 1 choice
> >> Feb 25 20:19:14 alekhine kernel: [ 79.138166] input: Logitech USB Mouse as /devices/pci0000:00/0000:00:10.0/usb2/2-1/2-1:1.0/input/input5
> >> Feb 25 20:19:14 alekhine kernel: [ 79.180828] input: USB HID v1.10 Mouse [Logitech USB Mouse] on usb-0000:00:10.0-1
> >> Feb 25 20:19:14 alekhine kernel: [ 79.181059] usb 2-2: USB disconnect, address 3
> >> Feb 25 20:19:15 alekhine kernel: [ 79.436567] usb 2-2: new low speed USB device using uhci_hcd and address 5
> >> Feb 25 20:19:15 alekhine kernel: [ 79.606180] usb 2-2: configuration #1 chosen from 1 choice
> >> Feb 25 20:19:15 alekhine kernel: [ 79.623893] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.0/input/input6
> >> Feb 25 20:19:15 alekhine kernel: [ 79.663140] input: USB HID v1.11 Keyboard [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> >> Feb 25 20:19:15 alekhine kernel: [ 79.697610] input: Microsoft Microsoft<AE> Digital Media Pro Keyboard as /devices/pci0000:00/0000:00:10.0/usb2/2-2/2-2:1.1/input/input7
> >> Feb 25 20:19:15 alekhine kernel: [ 79.721948] input: USB HID v1.11 Device [Microsoft Microsoft<AE> Digital Media Pro Keyboard] on usb-0000:00:10.0-2
> >>
> >>
> >> I don't see anything there that would explain the failure, but the console never comes back, and I am forced to hard reset the box. Anything else I can try?
> >>
> >
> > So machine works but video is that? See suspend.sf.net...
> >
>
> I haven't done too much looking at what the tool on that site does,
> but I was under the impression that I should be able to do:
>
> echo mem > /sys/power/state
>
> and then bring the system back up and have it work. If that is
> not expected to work, then I won't bother trying it again. My
> goal in all this is to help test the kernel, and provide feedback
> and testing for features that are expected to work. If this is
> expected to work, then I would rather provide testing for patches
> to the kernel that will make this work, rather than relying on
> userspace tricks to get around a broken kernel (because frankly,
> I couldn't care much less if STR works for me or not - I was just
> testing it to be helpful).
>
> Am I wrong about this? Is the tool at suspend.sf.net supposed to
> be required for STR to work with current linux kernels?
That depends on the hardware configuration, really. On some systems
# echo mem > /sys/power/state
works out of the box, but on some of them we need to run some real mode
quirks from the user space to bring the graphics card back on line. That's
what s2ram is needed for.
Now, if you manage to find the combination of s2ram options appropriate for
your system, so that it can suspend and resume successfully, it will be very
helpful if you periodically test this functionality on new kernels to make sure
there are no regressions.
Thanks,
Rafael
On Tue, Feb 26, 2008 at 08:28:39PM -0400, Kevin Winchester wrote:
> I haven't done too much looking at what the tool on that site does,
> but I was under the impression that I should be able to do:
>
> echo mem > /sys/power/state
>
> and then bring the system back up and have it work.
Not if you want video to come back on most hardware - the kernel has no
idea how to reinitialise your graphics card. s2ram and similar tools
attempt to deal with this by reprogramming it from userspace. On the
other hand, if it did work on the same hardware with earlier kernels,
then that's a bug.
--
Matthew Garrett | [email protected]