Date:	Sun, 24 Feb 2008 14:19:23 -0400
From:	Kevin Winchester <kjwinchester@...il.com>
To:	Stephen Rothwell <sfr@...b.auug.org.au>
CC:	linux-next@...r.kernel.org, LKML <linux-kernel@...r.kernel.org>,
	len.brown@...el.com, pavel@...e.cz, rjw@...k.pl,
	linux-pm@...ts.linux-foundation.org
Subject: Re: linux-next: Tree for Feb 24

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
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists