From Your Debug msg, Its look like that Your USB device have larger delay, Because when USB device is connected then it always send a small dummy pkt at fixed interval of time. I think that pkt is delayed through the threshold value, so its athen create USB disconnect.
Regards:
Pulkit Goel
mail: email@xxxxxxxxxxxxxx
vipulkit.goel@xxxxxxxxx
On Mon, Feb 8, 2010 at 8:42 PM, George Kadianakis <desnacked@xxxxxxxxx> wrote:
Greetings,
I'm encountering problems while trying to connect my digital camera
(Canon EOS 450D) to my Linux box.
Basically, when I plug in the camera (USB) dmesg shows the following:
>usb 1-8: new high speed USB device using ehci_hcd and address 11
>ehci_hcd 0000:00:1d.7: port 8 high speed
>ehci_hcd 0000:00:1d.7: GetStatus port 8 status 001005 POWER sig=se0PE
>CONNECT
>usb 1-8: default language 0x0409
>usb 1-8: udev 11, busnum 1, minor = 10
>usb 1-8: New USB device found, idVendor=04a9, idProduct=3145
>usb 1-8: New USB device strings: Mfr=1, Product=2, SerialNumber=0
>usb 1-8: Product: Canon Digital Camera
>usb 1-8: Manufacturer: Canon Inc.
>usb 1-8: uevent
>usb 1-8: usb_probe_device
>usb 1-8: configuration #1 chosen from 1 choice
>usb 1-8: adding 1-8:1.0 (config #1, interface 0)
>usb 1-8:1.0: uevent
>drivers/usb/core/inode.c: creating file '011'
>usb 1-8: uevent
>usb 1-8: uevent
That's fairly okay and if I check the output of lsusb or gphoto2, my
Canon camera gets recognized normally.
Thing is, that after some seconds, the USB system goes into
a weird suspend/wakeup/disconnect cycle. dmesg gives:
>usb usb5: usb auto-resume
>usb usb5: wakeup_rh
>hub 5-0:1.0: hub_resume
>hub 5-0:1.0: state 7 ports 2 chg 0000 evt 0000
>usb usb4: usb auto-resume
>usb usb4: wakeup_rh
>hub 4-0:1.0: hub_resume
>hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
>usb usb2: usb auto-resume
>usb usb2: wakeup_rh
>hub 2-0:1.0: hub_resume
>hub 2-0:1.0: state 7 ports 2 chg 0000 evt 0000
>usb usb5: suspend_rh (auto-stop)
>usb usb4: suspend_rh (auto-stop)
>usb usb2: suspend_rh (auto-stop)
>hub 5-0:1.0: hub_suspend
>usb usb5: bus auto-suspend
>usb usb5: suspend_rh
>hub 4-0:1.0: hub_suspend
>usb usb4: bus auto-suspend
>usb usb4: suspend_rh
>hub 2-0:1.0: hub_suspend
>usb usb2: bus auto-suspend
>usb usb2: suspend_rh
>hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100
>ehci_hcd 0000:00:1d.7: GetStatus port 8 status 001002 POWER sig=se0CSC
>hub 1-0:1.0: port 8, status 0100, change 0001, 12 Mb/s
>usb 1-8: USB disconnect, address 11
>usb 1-8: unregistering device
>usb 1-8: usb_disable_device nuking all URBs
>usb 1-8: unregistering interface 1-8:1.0
>usb 1-8:1.0: uevent
>usb 1-8: uevent
>hub 1-0:1.0: debounce: port 8: total 100ms stable 100ms status 0x100
>hub 1-0:1.0: hub_suspend
>usb usb1: bus auto-suspend
>ehci_hcd 0000:00:1d.7: suspend root hub
>usb usb1: usb auto-resume
>ehci_hcd 0000:00:1d.7: resume root hub
Plugging in the camera with usbmon active, I get the following:
>f675d700 3784842750 S Ci:1:001:0 s a3 00 0000 0001 0004 4 <
>f675d700 3784842763 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842779 S Ci:1:001:0 s a3 00 0000 0002 0004 4 <
>f675d700 3784842781 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842783 S Ci:1:001:0 s a3 00 0000 0003 0004 4 <
>f675d700 3784842785 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842787 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
>f675d700 3784842789 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842791 S Ci:1:001:0 s a3 00 0000 0005 0004 4 <
>f675d700 3784842793 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842794 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
>f675d700 3784842805 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842807 S Ci:1:001:0 s a3 00 0000 0007 0004 4 <
>f675d700 3784842809 C Ci:1:001:0 0 4 = 00010000
>f675d700 3784842811 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f675d700 3784842824 C Ci:1:001:0 0 4 = 01050100
>f675d700 3784842839 S Co:1:001:0 s 23 01 0010 0008 0000 0
>f675d700 3784842842 C Co:1:001:0 0 0
>f71edf00 3784943739 S Ii:1:001:1 -115:2048 4 <
>f675d700 3784943784 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f675d700 3784943792 C Ci:1:001:0 0 4 = 01050000
>f675d700 3784943819 S Co:1:001:0 s 23 03 0004 0008 0000 0
>f675d700 3784943823 C Co:1:001:0 0 0
>f675d700 3784994741 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f675d700 3784995004 C Ci:1:001:0 0 4 = 03051000
>f675d700 3785045739 S Co:1:001:0 s 23 01 0014 0008 0000 0
>f675d700 3785045747 C Co:1:001:0 0 0
>f675d700 3785045773 S Ci:1:000:0 s 80 06 0100 0000 0040 64 <
>f675d700 3785046514 C Ci:1:000:0 0 18 = 12010002 00000040 a9044531 02000102 0001
>f675d700 3785046532 S Co:1:001:0 s 23 03 0004 0008 0000 0
>f675d700 3785046536 C Co:1:001:0 0 0
>f675d700 3785096733 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f675d700 3785097050 C Ci:1:001:0 0 4 = 03051000
>f675d700 3785147739 S Co:1:001:0 s 23 01 0014 0008 0000 0
>f675d700 3785147749 C Co:1:001:0 0 0
>f675d700 3785147754 S Co:1:000:0 s 00 05 000e 0000 0000 0
>f675d700 3785147808 C Co:1:000:0 0 0
>f675d700 3785159806 S Ci:1:014:0 s 80 06 0100 0000 0012 18 <
>f675d700 3785181211 C Ci:1:014:0 0 18 = 12010002 00000040 a9044531 02000102 0001
>f675d700 3785181240 S Ci:1:014:0 s 80 06 0200 0000 0009 9 <
>f675d700 3785181822 C Ci:1:014:0 0 9 = 09022700 010100c0 01
>f675d700 3785181841 S Ci:1:014:0 s 80 06 0200 0000 0027 39 <
>f675d700 3785182448 C Ci:1:014:0 0 39 = 09022700 010100c0 01090400 00030601 01000705 81020002 00070502 02000200
>f675d700 3785182462 S Ci:1:014:0 s 80 06 0300 0000 00ff 255 <
>f675d700 3785183081 C Ci:1:014:0 0 4 = 04030904
>f675d700 3785183095 S Ci:1:014:0 s 80 06 0302 0409 00ff 255 <
>f675d700 3785183573 C Ci:1:014:0 0 42 = 2a034300 61006e00 6f006e00 20004400 69006700 69007400 61006c00 20004300
>f675d700 3785183590 S Ci:1:014:0 s 80 06 0301 0409 00ff 255 <
>f675d700 3785184200 C Ci:1:014:0 0 22 = 16034300 61006e00 6f006e00 20004900 6e006300 2e00
>f675d700 3785184419 S Co:1:014:0 s 00 09 0001 0000 0000 0
>f675d700 3785184448 C Co:1:014:0 0 0
After three or four seconds, the following appears:
>>f71edf00 3813862200 C Ii:1:001:1 0:2048 2 = 0001
>>f71edf00 3813862208 S Ii:1:001:1 -115:2048 4 <
>f66dad00 3813862754 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f66dad00 3813862782 C Ci:1:001:0 0 4 = 00010100
>f66dad00 3813862786 S Co:1:001:0 s 23 01 0010 0008 0000 0
>f66dad00 3813862789 C Co:1:001:0 0 0
>f66dad00 3813863355 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f66dad00 3813863362 C Ci:1:001:0 0 4 = 00010000
>f6747600 3813888979 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f6747600 3813888996 C Ci:1:001:0 0 4 = 00010000
>f6747600 3813914744 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f6747600 3813914752 C Ci:1:001:0 0 4 = 00010000
>f6747600 3813940988 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f6747600 3813941004 C Ci:1:001:0 0 4 = 00010000
>f6747600 3813966730 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
>f6747600 3813966748 C Ci:1:001:0 0 4 = 00010000
>f71edf00 3816875761 C Ii:1:001:1 -2:2048 0
The behavior is not always exactly the same. For example, some times,
I won't get any suspend/wakeup messages. Other times, the last USB
transfer before the first stabilization (which in the example above
is:
>f675d700 3785184448 C Co:1:014:0 0 0
would be something like this:
>f71edf00 3816875761 C Ii:1:001:1 -2:2048 0
Excuse me if all this sounds like a bug report, but I'm hesitating
posting it in Kernel's bugzilla because the unstability of the issue
makes me think that it's hardware's fault (I tried all my PC's USB
ports and the issue remains).
Anyway, what I would like is some help in figuring out what the double
quoted lines in the usbmon output are. I can't find information on
USB Interrupt types/codes so I can't really interpret what:
>f71edf00 3813862200 C Ii:1:001:1 0:2048 2 = 0001
>f71edf00 3813862208 S Ii:1:001:1 -115:2048 4 <
is, even though it looks like it's the 'cause' of the problem.
Thank you very much and sorry for the shameless log pasting ;)
--
To unsubscribe from this list: send an email with
"unsubscribe kernelnewbies" to ecartis@xxxxxxxxxxxx
Please read the FAQ at http://kernelnewbies.org/FAQ
