2012/3/17 Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx>: > Eric Fu reports a problem with his VIA host controller fetching a zeroed > event ring pointer on resume from suspend. The host should have been > halted, but we can't be sure because that code ignores the return value > from xhci_halt(). Print a warning when the host controller refuses to > halt within XHCI_MAX_HALT_USEC (currently 16 seconds). Hi, Sarah. I tested the patch. And the message you added wasn't showed. I checked the time took by halting the host and found the host would be stopped after 1 microsecond. From the hibernate dmesg log, you can find a host system error at 76.789330, then the kernel panic happened. hibernate dmesg log: [ 74.587642] EXT4-fs (sda2): re-mounted. Opts: errors=remount-ro,commit=0 [ 75.859908] PM: Marking nosave pages: 000000000009f000 - 0000000000100000 [ 75.859956] PM: Basic memory bitmaps created [ 75.859986] PM: Syncing filesystems ... done. [ 76.018463] Freezing user space processes ... (elapsed 0.01 seconds) done. [ 76.032865] PM: Preallocating image memory... done (allocated 148037 pages) [ 76.086116] PM: Allocated 592148 kbytes in 0.05 seconds (11842.96 MB/s) [ 76.086149] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done. [ 76.100965] Suspending console(s) (use no_console_suspend to debug) [ 76.101134] sd 0:0:1:0: [sda] Synchronizing SCSI cache [ 76.101241] xhci_hcd 0000:01:00.0: WARN Event TRB for slot 2 ep 3 with no TDs queued? [ 76.101351] xhci_hcd 0000:01:00.0: WARN Event TRB for slot 2 ep 2 with no TDs queued? [ 76.101506] xhci_hcd 0000:01:00.0: WARN Event TRB for slot 2 ep 0 with no TDs queued? [ 76.220829] PM: freeze of devices complete after 119.801 msecs [ 76.221208] PM: late freeze of devices complete after 0.376 msecs [ 76.221597] ACPI: Preparing to enter system sleep state S4 [ 76.222031] PM: Saving platform NVS memory [ 76.222055] Disabling non-boot CPUs ... [ 76.324803] CPU 1 is now offline [ 76.428854] CPU 2 is now offline [ 76.429910] Broke affinity for irq 19 [ 76.429923] Broke affinity for irq 42 [ 76.532881] CPU 3 is now offline [ 76.533302] PM: Creating hibernation image: [ 76.555685] PM: Need to copy 147008 pages [ 76.555687] PM: Normal pages needed: 51314 + 1024, available pages: 175866 [ 76.533324] PM: Restoring platform NVS memory [ 76.533713] Enabling non-boot CPUs ... [ 76.533784] Booting Node 0 Processor 1 APIC 0x4 [ 76.533785] smpboot cpu 1: start_ip = 9b000 [ 76.543940] Initializing CPU#1 [ 76.544828] Calibrating delay loop (skipped) already calibrated this CPU [ 76.565478] CPU1 is up [ 76.566177] Booting Node 0 Processor 2 APIC 0x1 [ 76.566181] smpboot cpu 2: start_ip = 9b000 [ 76.576338] Initializing CPU#2 [ 76.577228] Calibrating delay loop (skipped) already calibrated this CPU [ 76.597997] CPU2 is up [ 76.598168] Booting Node 0 Processor 3 APIC 0x5 [ 76.598172] smpboot cpu 3: start_ip = 9b000 [ 76.608231] Initializing CPU#3 [ 76.609120] Calibrating delay loop (skipped) already calibrated this CPU [ 76.629836] CPU3 is up [ 76.632176] ACPI: Waking up from system sleep state S4 [ 76.633244] PM: early restore of devices complete after 0.672 msecs [ 76.662107] i915 0000:00:02.0: setting latency timer to 64 [ 76.662145] uhci_hcd 0000:00:1a.0: setting latency timer to 64 [ 76.662148] uhci_hcd 0000:00:1a.1: setting latency timer to 64 [ 76.662167] usb usb1: root hub lost power or was reset [ 76.662170] usb usb2: root hub lost power or was reset [ 76.662180] uhci_hcd 0000:00:1a.2: setting latency timer to 64 [ 76.662182] ehci_hcd 0000:00:1a.7: setting latency timer to 64 [ 76.662201] usb usb3: root hub lost power or was reset [ 76.662205] uhci_hcd 0000:00:1d.0: setting latency timer to 64 [ 76.662214] uhci_hcd 0000:00:1d.1: setting latency timer to 64 [ 76.662228] usb usb4: root hub lost power or was reset [ 76.662239] usb usb5: root hub lost power or was reset [ 76.662241] uhci_hcd 0000:00:1d.2: setting latency timer to 64 [ 76.662252] ehci_hcd 0000:00:1d.7: setting latency timer to 64 [ 76.662255] snd_hda_intel 0000:00:1b.0: irq 44 for MSI/MSI-X [ 76.662261] usb usb6: root hub lost power or was reset [ 76.662277] pci 0000:00:1e.0: setting latency timer to 64 [ 76.662282] ata_piix 0000:00:1f.2: setting latency timer to 64 [ 76.662290] ata_piix 0000:00:1f.5: setting latency timer to 64 [ 76.662292] usb usb9: root hub lost power or was reset [ 76.662294] usb usb10: root hub lost power or was reset [ 76.662510] xhci_hcd 0000:01:00.0: irq 42 for MSI/MSI-X [ 76.662560] usb usb7: root hub lost power or was reset [ 76.666442] ehci_hcd 0000:00:1a.7: cache line size of 64 is not supported [ 76.666456] usb usb8: root hub lost power or was reset [ 76.670351] ehci_hcd 0000:00:1d.7: cache line size of 64 is not supported [ 76.789330] xhci_hcd 0000:01:00.0: WARNING: Host System Error [ 76.789339] irq event 42: bogus return value ffffff94 [ 76.789342] Pid: 1941, comm: kworker/u:30 Not tainted 3.3.0-rc7+ #4 [ 76.789344] Call Trace: [ 76.789352] [<c01a1c29>] __report_bad_irq+0x29/0xd0 [ 76.789355] [<c01a1db2>] note_interrupt+0xe2/0x1c0 [ 76.789358] [<c019fb59>] handle_irq_event_percpu+0xa9/0x1e0 [ 76.789361] [<c0126968>] ? default_spin_lock_flags+0x8/0x10 [ 76.789364] [<c019fccb>] handle_irq_event+0x3b/0x60 [ 76.789366] [<c01a2a70>] ? handle_level_irq+0xd0/0xd0 [ 76.789369] [<c01a2ad0>] handle_edge_irq+0x60/0x100 [ 76.789371] <IRQ> [<c05e7cb2>] ? do_IRQ+0x42/0xc0 [ 76.789379] [<c0164c0e>] ? dequeue_task_fair+0x17e/0x220 [ 76.789381] [<c05e7bf0>] ? common_interrupt+0x30/0x38 [ 76.789383] [<c015df08>] ? finish_task_switch+0x48/0xd0 [ 76.789387] [<c05df7cb>] ? __schedule+0x3ab/0x7a0 [ 76.789401] [<f8ab3078>] ? usb_api_blocking_completion+0x18/0x20 [usbcore] [ 76.789407] [<f8ab096f>] ? usb_hcd_giveback_urb+0x5f/0xc0 [usbcore] [ 76.789413] [<f8ab1a04>] ? usb_hcd_submit_urb+0x2b4/0x6b0 [usbcore] [ 76.789415] [<c05e0a18>] ? _raw_spin_lock_irq+0x18/0x20 [ 76.789417] [<c05dfd70>] ? wait_for_common+0xf0/0x120 [ 76.789419] [<c0126968>] ? default_spin_lock_flags+0x8/0x10 [ 76.789421] [<c05e09df>] ? _raw_spin_lock_irqsave+0x2f/0x50 [ 76.789423] [<c05dfeb5>] ? schedule+0x35/0x50 [ 76.789425] [<c05de2d4>] ? schedule_timeout+0x134/0x260 [ 76.789429] [<c013f210>] ? lock_timer_base+0x60/0x60 [ 76.789431] [<c05de41a>] ? schedule_timeout_uninterruptible+0x1a/0x20 [ 76.789433] [<c01408ed>] ? msleep+0x1d/0x30 [ 76.789438] [<f8aaaf73>] ? hub_power_on+0x63/0x70 [usbcore] [ 76.789444] [<f8aacde1>] ? hub_activate+0x61/0x440 [usbcore] [ 76.789446] [<c013f210>] ? lock_timer_base+0x60/0x60 [ 76.789447] [<c0126968>] ? default_spin_lock_flags+0x8/0x10 [ 76.789449] [<c05e09df>] ? _raw_spin_lock_irqsave+0x2f/0x50 [ 76.789455] [<f8aad23a>] ? hub_reset_resume+0x1a/0x20 [usbcore] [ 76.789461] [<f8ab4fe8>] ? usb_resume_interface+0x68/0x100 [usbcore] [ 76.789468] [<f8ab50f7>] ? usb_resume_both+0x77/0x140 [usbcore] [ 76.789474] [<f8ab6027>] ? usb_resume+0x47/0xb0 [usbcore] [ 76.789479] [<f8aaa110>] ? usb_disabled+0x20/0x20 [usbcore] [ 76.789484] [<f8aaa122>] ? usb_dev_restore+0x12/0x20 [usbcore] [ 76.789487] [<c042aea3>] ? dpm_run_callback+0x33/0x80 [ 76.789489] [<c042cf25>] ? pm_runtime_enable+0x45/0x70 [ 76.789491] [<c042b56c>] ? device_resume+0xcc/0x1b0 [ 76.789493] [<c042b66e>] ? async_resume+0x1e/0x50 [ 76.789496] [<c0157339>] ? async_run_entry_fn+0x69/0x170 [ 76.789499] [<c0149c1e>] ? process_one_work+0x10e/0x3b0 [ 76.789501] [<c0149245>] ? start_worker+0x25/0x30 [ 76.789503] [<c01572d0>] ? async_schedule+0x20/0x20 [ 76.789505] [<c014bf50>] ? worker_thread+0x140/0x3b0 [ 76.789507] [<c014be10>] ? manage_workers+0x1f0/0x1f0 [ 76.789509] [<c01501fc>] ? kthread+0x7c/0x90 [ 76.789511] [<c0150180>] ? kthread_freezable_should_stop+0x60/0x60 [ 76.789513] [<c05e7bfe>] ? kernel_thread_helper+0x6/0x10 [ 76.789515] handlers: [ 76.789518] [<f81a2cb0>] xhci_msi_irq [ 77.000005] ata4: SATA link down (SStatus 0 SControl 300) [ 77.010599] ata3: SATA link down (SStatus 0 SControl 300) [ 77.010648] usb 10-1: Cannot reset HCD device state [ 77.121404] usb 9-1: Cannot reset HCD device state [ 77.320171] ata2.00: SATA link down (SStatus 0 SControl 300) [ 77.320182] ata2.01: SATA link down (SStatus 0 SControl 300) [ 77.465540] ata1.00: SATA link down (SStatus 0 SControl 300) [ 77.465554] ata1.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 77.481675] ata1.01: ACPI cmd ef/03:45:00:00:00:b0 (SET FEATURES) filtered out [ 77.481682] ata1.01: ACPI cmd ef/03:45:00:00:00:b0 (SET FEATURES) filtered out [ 77.481688] ata1.01: ACPI cmd ef/03:0c:00:00:00:b0 (SET FEATURES) filtered out [ 77.497970] ata1.01: configured for UDMA/133 [ 77.498320] sd 0:0:1:0: [sda] Starting disk [ 77.501404] PM: restore of devices complete after 839.144 msecs [ 77.601339] PM: Image restored successfully. [ 77.602540] Restarting tasks ... [ 77.602630] usb 10-1: USB disconnect, device number 2 [ 77.607255] done. [ 77.608594] PM: Basic memory bitmaps freed [ 77.622046] BUG: unable to handle kernel NULL pointer dereference at 00000024 [ 77.623858] IP: [<f8198f99>] xhci_free_dev+0x69/0x130 [xhci_hcd] [ 77.625701] *pde = 00000000 [ 77.627603] Oops: 0002 [#1] SMP [ 77.627606] Modules linked in: binfmt_misc parport_pc ppdev snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep usb_storage snd_pcm snd_seq_midi snd_rawmidi snd_seq_midi_event i915 drm_kms_helper drm psmouse snd_seq snd_timer snd_seq_device snd xhci_hcd lp parport soundcore snd_page_alloc i2c_algo_bit video intel_agp intel_gtt agpgart serio_raw ehci_hcd uhci_hcd r8169 mii usbcore usb_common [ 77.627633] [ 77.627639] Pid: 212, comm: khubd Not tainted 3.3.0-rc7+ #4 Gigabyte Technology Co., Ltd. H55M-S2/H55M-S2 [ 77.627643] EIP: 0060:[<f8198f99>] EFLAGS: 00010202 CPU: 2 [ 77.627649] EIP is at xhci_free_dev+0x69/0x130 [xhci_hcd] [ 77.627651] EAX: 00000000 EBX: 00000000 ECX: f15fa000 EDX: f15fa000 [ 77.627654] ESI: 00000001 EDI: 00000000 EBP: f56afed4 ESP: f56afeb0 [ 77.627656] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 [ 77.627659] Process khubd (pid: 212, ti=f56ae000 task=f14a3240 task.ti=f56ae000) [ 77.627661] Stack: [ 77.627662] 00000000 00000001 f81a49c0 f55b8800 ed198400 f15fa000 f55b8800 ed198400 [ 77.627667] ed25b69c f56aff00 f8aada7c f55b8864 f8ac16c8 00000002 ed25b69c f55b8898 [ 77.627671] f55b8864 00000001 ed19a400 00000001 f56affb8 f8aae20e f56affa4 92a7a867 [ 77.627675] Call Trace: [ 77.627692] [<f8aada7c>] usb_disconnect+0x10c/0x120 [usbcore] [ 77.627702] [<f8aae20e>] hub_thread+0x54e/0x1020 [usbcore] [ 77.627712] [<c0150620>] ? wake_up_bit+0x70/0x70 [ 77.627716] [<c015007b>] ? kthread_worker_fn+0xcb/0x170 [ 77.627725] [<f8aadcc0>] ? hub_disconnect+0xe0/0xe0 [usbcore] [ 77.627732] [<c01501fc>] kthread+0x7c/0x90 [ 77.627735] [<c0150180>] ? kthread_freezable_should_stop+0x60/0x60 [ 77.627741] [<c05e7bfe>] kernel_thread_helper+0x6/0x10 [ 77.627742] Code: f8 ed 0f 85 c2 00 00 00 8b 83 30 03 00 00 31 f6 8b 55 f0 8b 84 82 90 00 00 00 89 5d e8 89 c7 89 c3 90 69 c6 8c 00 00 00 83 c6 01 <83> 67 24 fb 81 c7 8c 00 00 00 8d 44 03 3c e8 d4 6c fa c7 83 fe [ 77.627767] EIP: [<f8198f99>] xhci_free_dev+0x69/0x130 [xhci_hcd] SS:ESP 0068:f56afeb0 [ 77.627773] CR2: 0000000000000024 [ 77.641463] ---[ end trace 2ec0cdb425f94828 ]--- [ 77.689082] r8169 0000:03:00.0: eth0: link down [ 77.689088] r8169 0000:03:00.0: eth0: link down [ 77.689232] ADDRCONF(NETDEV_UP): eth0: link is not ready [ 77.945861] psmouse serio1: hgpk: ID: 10 00 50 [ 78.785025] EXT4-fs (sda2): re-mounted. Opts: errors=remount-ro,commit=0 [ 79.219106] r8169 0000:03:00.0: eth0: link up [ 79.219285] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready > > Signed-off-by: Sarah Sharp <sarah.a.sharp@xxxxxxxxxxxxxxx> > --- > drivers/usb/host/xhci.c | 3 +++ > 1 files changed, 3 insertions(+), 0 deletions(-) > > diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c > index c939f5f..9fc2be4 100644 > --- a/drivers/usb/host/xhci.c > +++ b/drivers/usb/host/xhci.c > @@ -106,6 +106,9 @@ int xhci_halt(struct xhci_hcd *xhci) > STS_HALT, STS_HALT, XHCI_MAX_HALT_USEC); > if (!ret) > xhci->xhc_state |= XHCI_STATE_HALTED; > + else > + xhci_warn(xhci, "Host not halted after %u microseconds.\n", > + XHCI_MAX_HALT_USEC); > return ret; > } > > -- > 1.7.9 > -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
