Hi Alan, we have an issue here where the hub code discards a remote wakeup. Regards Oliver > I've been testing the new fix and with additional debug prints. > It seems I cannot reproduce the issue but I am hitting the other known > issue > where remote wakeup is signaled by the device but kernel never acts on > it. > However now this problem is much more evident than ever before. Please > find > two occurrences below. > > --------------------- First ----------------------------- > > 2009-10-29 03:37:12.839:I:Opening /dev/ttyACM3 > > 2009-10-29T03:37:12.841+09:00 Ubuntu kernel: [ 2153.478875] usb usb7: > usb auto-resume > 2009-10-29T03:37:12.841+09:00 Ubuntu kernel: [ 2153.478881] ehci_hcd > 0000:00:1d.7: resume root hub > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528072] usb usb7: > usb_resume_device: status 0 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528078] hub 7-0:1.0: > hub_resume > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528102] hub 7-0:1.0: > port 4: status 0507 change 0000 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528115] hub 7-0:1.0: > usb_resume_interface: status 0 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528119] usb usb7: > usb_resume_both: status 0 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528123] usb usb7: > usb_autoresume_device: status 0 cnt 1 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528131] hub 7-0:1.0: > state 7 ports 6 chg 0000 evt 0000 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528135] hub 7-0:1.0: > usb_autopm_get_interface: status 0 cnt 2 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528140] usb usb7: > usb_suspend_both: status -16 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528144] hub 7-0:1.0: > usb_autopm_set_interface: status -16 cnt 0 > 2009-10-29T03:37:12.893+09:00 Ubuntu kernel: [ 2153.528157] usb 7-4: usb > auto-resume > 2009-10-29T03:37:12.925+09:00 Ubuntu kernel: [ 2153.560167] ehci_hcd > 0000:00:1d.7: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576066] usb 7-4: > finish resume > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576700] usb 7-4: > usb_resume_device: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576705] usb 7-4:1.0: > usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576710] cdc_acm > 7-4:1.1: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576714] cdc_acm > 7-4:1.2: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576718] cdc_acm > 7-4:1.3: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576723] cdc_acm > 7-4:1.4: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576727] cdc_wdm > 7-4:1.5: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576731] cdc_wdm > 7-4:1.6: usb_resume_interface: status 0 > 2009-10-29T03:37:12.941+09:00 Ubuntu kernel: [ 2153.576735] cdc_ether > 7-4:1.7: usb_resume_interface: status 0 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576742] cdc_ether > 7-4:1.8: usb_resume_interface: status 0 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576746] cdc_acm > 7-4:1.9: usb_resume_interface: status 0 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576755] cdc_acm > 7-4:1.10: usb_resume_interface: status 0 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576759] usb 7-4: > usb_resume_both: status 0 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576763] cdc_acm > 7-4:1.1: usb_autopm_get_interface: status 0 cnt 1 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576772] ehci_hcd > 0000:00:1d.7: reused qh f66d3840 schedule > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.576777] usb 7-4: > link qh16-0001/f66d3840 start 5 [1/0 us] > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.577210] usb 7-4: > usb_suspend_both: status -11 > 2009-10-29T03:37:12.942+09:00 Ubuntu kernel: [ 2153.577215] cdc_acm > 7-4:1.1: usb_autopm_put_interface: status -11 cnt 0 > > 2009-10-29 03:37:12.997:I:Control: --> 10, "AT+CFUN=1 " > > 2009-10-29 03:37:13.053:I:AT: <-- 11, "+CREG: 2,4 " > 2009-10-29 03:37:13.053:I:AT: <-- 3, "OK " > > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.000182] usb 7-4:1.0: > usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.000206] usb 7-4: > unlink qh16-0001/f66d3840 start 5 [1/0 us] > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002731] cdc_acm > 7-4:1.1: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002740] cdc_acm > 7-4:1.2: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002747] cdc_acm > 7-4:1.3: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002753] cdc_acm > 7-4:1.4: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002761] cdc_wdm > 7-4:1.5: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002768] cdc_wdm > 7-4:1.6: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002778] cdc_ether > 7-4:1.7: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.365+09:00 Ubuntu kernel: [ 2156.002784] cdc_ether > 7-4:1.8: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.366+09:00 Ubuntu kernel: [ 2156.002791] cdc_acm > 7-4:1.9: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.366+09:00 Ubuntu kernel: [ 2156.002797] cdc_acm > 7-4:1.10: usb_suspend_interface: status 0 > 2009-10-29T03:37:15.366+09:00 Ubuntu kernel: [ 2156.003227] usb 7-4: usb > auto-suspend > 2009-10-29T03:37:15.382+09:00 Ubuntu kernel: [ 2156.017053] usb 7-4: > usb_suspend_device: status 0 > 2009-10-29T03:37:15.382+09:00 Ubuntu kernel: [ 2156.017064] usb usb7: > usb_suspend_both: status -11 > 2009-10-29T03:37:15.382+09:00 Ubuntu kernel: [ 2156.017068] usb usb7: > usb_autosuspend_device: cnt 0 > 2009-10-29T03:37:15.382+09:00 Ubuntu kernel: [ 2156.017072] usb 7-4: > usb_suspend_both: status 0 > 2009-10-29T03:37:15.382+09:00 Ubuntu kernel: [ 2156.017075] usb 7-4: > usb_autosuspend_work: cnt 0 > > (03:37:15.987000) 340037 USBLD_INFO: astose_devioctl.c:1198: Suspend > powersave enabled. > > (03:37:18.964000) 340781 AT/CEA-1, AT/PAS/Appl-->terminal , ChId:1, > UTF-8[ 0-25]:'+CREG: 1,"23FB","006EB3C7"' > (03:37:18.964000) 340782 USBLD_INFO: astose_devioctl.c:1207: Suspend > powersave disabled. > (03:37:18.964000) 340782 USBLD_INFO: astose_devioctl.c:376: > (03:37:18.964000) 340782 ****************** Signalling remote > wakeup****************** > > 2009-10-29T03:37:18.345+09:00 Ubuntu kernel: [ 2158.983913] ehci_hcd > 0000:00:1d.7: port 4 remote wakeup > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989121] hub 7-0:1.0: > hub_suspend > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989135] hub 7-0:1.0: > usb_suspend_interface: status 0 > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989142] usb usb7: > bus auto-suspend > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989147] ehci_hcd > 0000:00:1d.7: suspend root hub > > [Hub is suspended even if remote wakeup was signalled!] > > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989181] usb usb7: > usb_suspend_device: status 0 > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989188] usb usb7: > usb_suspend_both: status 0 > 2009-10-29T03:37:18.354+09:00 Ubuntu kernel: [ 2158.989193] usb usb7: > usb_autosuspend_work: cnt 0 > > --------------------- Second ----------------------------- > > 2009-10-29 13:01:46.783:I:Opening /dev/ttyACM1 > > 2009-10-29T13:01:46.785+09:00 Ubuntu kernel: [36027.422642] usb usb7: > usb auto-resume > 2009-10-29T13:01:46.785+09:00 Ubuntu kernel: [36027.422647] ehci_hcd > 0000:00:1d.7: resume root hub > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472170] usb usb7: > usb_resume_device: status 0 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472180] hub 7-0:1.0: > hub_resume > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472214] hub 7-0:1.0: > port 4: status 0507 change 0000 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472234] hub 7-0:1.0: > usb_resume_interface: status 0 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472239] usb usb7: > usb_resume_both: status 0 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472246] usb usb7: > usb_autoresume_device: status 0 cnt 1 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472258] hub 7-0:1.0: > state 7 ports 6 chg 0000 evt 0000 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472265] hub 7-0:1.0: > usb_autopm_get_interface: status 0 cnt 2 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472272] usb usb7: > usb_suspend_both: status -16 > 2009-10-29T13:01:46.837+09:00 Ubuntu kernel: [36027.472278] hub 7-0:1.0: > usb_autopm_set_interface: status -16 cnt 0 > 2009-10-29T13:01:46.838+09:00 Ubuntu kernel: [36027.472298] usb 7-4: usb > auto-resume > 2009-10-29T13:01:46.869+09:00 Ubuntu kernel: [36027.504190] ehci_hcd > 0000:00:1d.7: GetStatus port 4 status 001005 POWER sig=se0 PE CONNECT > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.520191] usb 7-4: > finish resume > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521087] usb 7-4: > usb_resume_device: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521096] usb 7-4:1.0: > usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521104] cdc_acm > 7-4:1.1: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521111] cdc_acm > 7-4:1.2: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521117] cdc_acm > 7-4:1.3: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521124] cdc_acm > 7-4:1.4: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521131] cdc_wdm > 7-4:1.5: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521137] cdc_wdm > 7-4:1.6: usb_resume_interface: status 0 > 2009-10-29T13:01:46.885+09:00 Ubuntu kernel: [36027.521143] cdc_ether > 7-4:1.7: usb_resume_interface: status 0 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521154] cdc_ether > 7-4:1.8: usb_resume_interface: status 0 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521160] cdc_acm > 7-4:1.9: usb_resume_interface: status 0 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521174] cdc_acm > 7-4:1.10: usb_resume_interface: status 0 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521180] usb 7-4: > usb_resume_both: status 0 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521187] cdc_acm > 7-4:1.1: usb_autopm_get_interface: status 0 cnt 1 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521203] ehci_hcd > 0000:00:1d.7: reused qh f48dbb00 schedule > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521211] usb 7-4: > link qh16-0001/f48dbb00 start 7 [1/0 us] > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521701] usb 7-4: > usb_suspend_both: status -11 > 2009-10-29T13:01:46.886+09:00 Ubuntu kernel: [36027.521709] cdc_acm > 7-4:1.1: usb_autopm_put_interface: status -11 cnt 0 > > 2009-10-29 13:01:46.938:I:Control: --> 10, "AT+CFUN=1 " > > 2009-10-29 13:01:47.001:I:AT: <-- 11, "+CREG: 2,4 " > 2009-10-29 13:01:47.001:I:AT: <-- 3, "OK " > > (13:01:47.726000) 464976 USBLD_INFO: astose_devioctl.c:1207: Suspend > powersave disabled. > > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.000185] usb 7-4:1.0: > usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.000208] usb 7-4: > unlink qh16-0001/f48dbb00 start 7 [1/0 us] > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004089] cdc_acm > 7-4:1.1: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004099] cdc_acm > 7-4:1.2: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004107] cdc_acm > 7-4:1.3: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004114] cdc_acm > 7-4:1.4: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004123] cdc_wdm > 7-4:1.5: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004130] cdc_wdm > 7-4:1.6: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004141] cdc_ether > 7-4:1.7: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.365+09:00 Ubuntu kernel: [36030.004147] cdc_ether > 7-4:1.8: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.366+09:00 Ubuntu kernel: [36030.004154] cdc_acm > 7-4:1.9: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.366+09:00 Ubuntu kernel: [36030.004162] cdc_acm > 7-4:1.10: usb_suspend_interface: status 0 > 2009-10-29T13:01:49.366+09:00 Ubuntu kernel: [36030.004618] usb 7-4: usb > auto-suspend > 2009-10-29T13:01:49.386+09:00 Ubuntu kernel: [36030.021214] usb 7-4: > usb_suspend_device: status 0 > 2009-10-29T13:01:49.386+09:00 Ubuntu kernel: [36030.021231] usb usb7: > usb_suspend_both: status -11 > 2009-10-29T13:01:49.386+09:00 Ubuntu kernel: [36030.021236] usb usb7: > usb_autosuspend_device: cnt 0 > 2009-10-29T13:01:49.386+09:00 Ubuntu kernel: [36030.021242] usb 7-4: > usb_suspend_both: status 0 > 2009-10-29T13:01:49.386+09:00 Ubuntu kernel: [36030.021247] usb 7-4: > usb_autosuspend_work: cnt 0 > > (13:01:50.733000) 465609 USBLD_INFO: astose_devioctl.c:1198: Suspend > powersave enabled. > > (13:01:53.652000) 466354 AT/CEA-1, AT/PAS/Appl-->terminal , ChId:1, > UTF-8[ 0-25]:'+CREG: 1,"23FB","006EB3C7"' > (13:01:53.652000) 466354 USBLD_INFO: astose_devioctl.c:1207: Suspend > powersave disabled. > (13:01:53.652000) 466354 USBLD_INFO: astose_devioctl.c:376: > (13:01:53.652000) 466354 ****************** Signalling remote > wakeup****************** > > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.986850] ehci_hcd > 0000:00:1d.7: port 4 remote wakeup > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988194] hub 7-0:1.0: > hub_suspend > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988209] hub 7-0:1.0: > usb_suspend_interface: status 0 > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988216] usb usb7: > bus auto-suspend > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988222] ehci_hcd > 0000:00:1d.7: suspend root hub > > [Hub is suspended even if remote wakeup was signalled!] > > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988257] usb usb7: > usb_suspend_device: status 0 > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988264] usb usb7: > usb_suspend_both: status 0 > 2009-10-29T13:01:52.349+09:00 Ubuntu kernel: [36032.988269] usb usb7: > usb_autosuspend_work: cnt 0 > > BR, > Rickard > > -----Original Message----- > From: Oliver Neukum [mailto:oliver@xxxxxxxxxx] > Sent: den 28 oktober 2009 18:37 > To: Rickard Bellini > Cc: Nicolas Chevillot; Torgny Johansson; Greg Heinrich; Carl Nordbeck; > Martin Chabot > Subject: Re: additional debug output for autosuspend in cdc-ether > > Am Montag, 26. Oktober 2009 16:35:22 schrieb Rickard Bellini: > > Yes, the fault sequence is repeatable, but the last message before > > expected autosuspend is not AT+CFUN=4. > > > > This issue is always triggered when releasing IP, taking down the > > usb0: > > interface and turning off the device radio. > > These operations are keeping the device from entering suspend for a > > few seconds. When the stream of commands are done, we are expecting > > the device to enter autosuspend. > > Hi, > > I found a bug that causes the device to never autosuspend again. > It is possibly not the bug you are seeing, but still here's the fix. > > Regards > Oliver -- 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