On Tue, 24 Nov 2009, Rickard Bellini wrote: > Hi, > > The log below, usbmon log attached. Okay. The usbmon clearly shows that the cdc-ether device was disconnected from the bus about 156 microseconds after the remote-wakeup resume signalling finished. It's possible that the disconnection occurred because the full-speed-to-high-speed transition failed (high-speed USB connections revert to full speed during suspend and go back to high-speed when they resume). This could be the fault of either the host controller hardware or the device. Here's the part of your log starting just before the autosuspend leading up to the failed autoresume. The timestamps look a little peculiar. > 2009-11-22T14:01:36.973+09:00 Ubuntu kernel: [134108.988142] usb 7-4: unlink qh16-0001/f6796f00 start 12 [1/0 us] > 2009-11-22T14:01:36.977+09:00 Ubuntu kernel: [134108.991212] usb 7-4: usb auto-suspend This was the start of the autosuspend. > (14:01:42.152000) 1920689 USBLD_INFO: astose_devioctl.c:1198: Suspend powersave enabled. > (14:01:42.841000) 1921154 USBLD_INFO: astose_devioctl.c:1207: Suspend powersave disabled. > (14:01:42.841000) 1921154 USBLD_INFO: astose_devioctl.c:376: > (14:01:42.841000) 1921154 > (14:01:42.841000) ****************** Signalling remote wakeup****************** > > (14:01:42.842000) 1921174 USBLD_INFO: astose_devioctl.c:1212: Detected RESET signaling on USB > > 2009-11-22T14:01:38.844+09:00 Ubuntu kernel: [134110.856474] ehci_hcd 0000:00:1d.7: port 4 remote wakeup And this was the start of the remote-wakeup signal. The kernel timestamps show that the device was suspended for 1.865 seconds. So why is the difference between the application timestamps above (42.841 - 42.152) only about 0.7 seconds? > 2009-11-22T14:01:38.861+09:00 Ubuntu kernel: [134110.876306] hub 7-0:1.0: state 7 ports 6 chg 0000 evt 0010 > 2009-11-22T14:01:38.861+09:00 Ubuntu kernel: [134110.876396] ehci_hcd 0000:00:1d.7: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT This marks the end of the resume signalling, 20 milliseconds after the start of the remote wakeup. > 2009-11-22T14:01:38.861+09:00 Ubuntu kernel: [134110.876421] usb 7-4: usb wakeup-resume Not shown in the kernel log, but present in the usbmon log, is an IRQ that occurred when the device was disconnected from the bus. It occurred at time 134110.876551, about 156 us after the resume signal ended. > 2009-11-22T14:01:38.917+09:00 Ubuntu kernel: [134110.932225] ehci_hcd 0000:00:1d.7: GetStatus port 4 status 001803 POWER sig=j CSC CONNECT > 2009-11-22T14:01:38.917+09:00 Ubuntu kernel: [134110.932252] usb 7-4: finish reset-resume 56 milliseconds later (the mdelay statement you added), we see the status resport. "CSC" stands for "Connect Status Changed", meaning there was a disconnection. And the hub driver realizes that something went wrong because it tries to carry out a reset-resume -- and this time it succeeded with not XactErr problem, thanks to the mdelay. Unfortunately the cdc-acm and cdc-ether drivers don't have reset-resume handlers, so the drivers were unbound and rebound anyway. In the end, the underlying problem is the disconnection. It caused those XactErr messages and the reset-resume. I don't know why the disconnect occurs, or why it occurs only some of the time. Maybe your host controller or device hardware (or both!) is slighly out of spec, so that the speed transition works most of the time but not all the time. Alan Stern -- 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
