Re: additional debug output for autosuspend in cdc-ether

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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

[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux