Please use Reply-To-All so that your messages get sent to the mailing
list as well as to me.
On Sat, 6 Jul 2013, Larry Keegan wrote:
> On Fri, 5 Jul 2013 17:41:25 -0400
> Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> wrote:
> > On Fri, 5 Jul 2013, Larry Keegan wrote:
> >
> > > Dear Chaps,
> > >
> > > I have a Microsoft Basic Optical mouse. When I used an earlier
> > > kernel (2.6 series) it just worked. However, now that I'm using
> > > 3.4.51 it suffers from USB disconnects and reconnects every 62
> > > seconds precisely. These disconnects do not occur whilst the mouse
> > > device is open. I have tried two different wired mice in different
> > > USB slots of different computers with different motherboard types,
> > > all to no avail.
> >
> > Can you post a usbmon trace showing some of those disconnects and
> > reconnects?
> >
>
> Dear Alan,
>
> Thank you very much for helping me to diagnose this problem.
>
> The following trace was made by waiting for a disconnect and
> reconnect event to complete, starting cat, waiting for another event
> and killing cat a few seconds afterwards.
>
> The mouse was plugged directly into the socket on the motherboard.
>
> # cat /sys/kernel/debug/usb/usbmon/4u
> e9921c00 2437517512 C Ii:4:001:1 0:128 1 = 04
> e9921c00 2437517523 S Ii:4:001:1 -115:128 2 <
> e7454480 2437517533 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454480 2437517543 C Ci:4:001:0 0 4 = 00010300
> e7454480 2437517545 S Co:4:001:0 s 23 01 0010 0002 0000 0
> e7454480 2437517548 C Co:4:001:0 0 0
> e7454480 2437517549 S Co:4:001:0 s 23 01 0011 0002 0000 0
> e7454480 2437517551 C Co:4:001:0 0 0
> e7454900 2437520222 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454900 2437520229 C Ci:4:001:0 0 4 = 00010000
> e7454480 2437545511 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454480 2437545518 C Ci:4:001:0 0 4 = 00010000
> e4411780 2437571511 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e4411780 2437571517 C Ci:4:001:0 0 4 = 00010000
> e7454480 2437597511 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454480 2437597517 C Ci:4:001:0 0 4 = 00010000
> e7454480 2437623509 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454480 2437623515 C Ci:4:001:0 0 4 = 00010000
> e9921c00 2439017513 C Ii:4:001:1 0:128 1 = 04
> e9921c00 2439017518 S Ii:4:001:1 -115:128 2 <
> e7454480 2439017523 S Ci:4:001:0 s a3 00 0000 0002 0004 4 <
> e7454480 2439017528 C Ci:4:001:0 0 4 = 01030100
...
This at least confirms that the disconnects do take place at the
hardware level. They aren't merely a software artifact.
> I can supply more if you tell me what configurations are most
> interesting.
No, I don't think usbmon will reveal anything more interesting than
this.
> > > What is interesting is that if I connect either mouse to the
> > > computer via a hub, the timing of the disconnects becomes irregular
> > > and unpredictable. I often find all the devices on the bus (ie.
> > > everything but the root hub) disconnect themselves at much the same
> > > time as the mouse does. Often the mouse doesn't reconnect to the
> > > bus. In any case plugging in either mouse makes that entire bus
> > > distinctly unreliable. This problem is not peculiar to any
> > > particular hub model.
It certainly sounds like something in the mice is causing all this
disturbance.
> > > I am using a virgin kernel and am not using a well-known user-space
> > > distribution. I use udev to set up my device nodes, but that's all.
> > > To me, this has a distinct whiff of USB suspend problems. I have
> > > attempted to turn off USB suspend by repeatedly writing 'on' to all
> > > the 'power/control' files under /sys/bus/usb/devices. It did not
> > > help. I also re-compiled the kernel with power management and usb
> > > suspend support removed. This didn't help either.
> >
> > That's a pretty clear indication that USB suspend is _not_ involved.
> >
> > > I'd appreciate some advice.
> >
> > It's possible this is an electrical problem -- the bus may not provide
> > enough power for all the devices on it.
>
> I doubt it's a power problem because:
>
> - I have tried 3 computers now, each with different motherboards.
> - One of the computers has had no hardware changes. It worked before I
> updated the kernel, but fails now.
> - The computers consist of nothing more than motherboard with
> integrated graphics, 35W or 65W Celeron CPU, RAM and single HDD. They
> are powered by 250, 450 and 750W power supplies respectively. One of
> the computers has a slim-line Radeon graphics card.
> - I've also tried connecting the mouse via a Startech USB2EXT4 CAT5 USB
> extender. This device is mains-powered on both the local and remote
> end.
Agreed, lack of power seems unlikely.
> EMI is also a possibility - both mains-borne and pick up from the
> unscreened mouse leads. Although I've not done any spectrum analysis, I
> have tried creating interference (mains and irradiated) and they seem
> pretty immune to upset. The other thing is, prior to doing the
> interference tests, the tangle of wires hadn't moved for months, as the
> dust testified.
>
> The other thing which makes me feel that power and EMI are unlikely to
> be the cause of the problem is the precise nature of the events. Here
> is a snippet from my syslog:
>
> # tail -f /var/log/messages | grep 'USB disconnect'
> 2013-07-06T11:27:19.518567Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 126
> 2013-07-06T11:28:21.518556Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 127
> 2013-07-06T11:29:23.518567Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 2
> 2013-07-06T11:30:25.518562Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 3
> 2013-07-06T11:31:27.518568Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 4
> 2013-07-06T11:32:29.518567Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 5
> 2013-07-06T11:33:31.518568Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 6
>
> These events occur with surprising regularity. Too regular for it to be
> an uncorrelated external event. Three mice, (two Microsoft, and one
> other) but all three containing the same PixArt chip all exhibit the
> same timing. If this were power droop I'd expect capacitor component
> tolerances to cause slightly different timings on the different mice,
> or different computers but they are microsecond perfect.
Yes. Obviously this is related to a hardware or software timer. The
microsecond perfection may not mean anything, however. Is this bus
connected to a UHCI controller? The uhci-hcd driver uses a software
timer for detecting port-connect changes; the timer runs at a steady
rate of precisely 4 times per second.
> Watch what happens when I physically unplug the mouse and plug it
> back in:
>
> 2013-07-06T11:42:49.518557Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 15
> 2013-07-06T11:43:51.518568Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 16
> 2013-07-06T11:44:28.713462Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 17
> 2013-07-06T11:47:41.268567Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 18
> 2013-07-06T11:48:43.268571Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 19
> 2013-07-06T11:49:45.268566Z {0.6} ud1 kernel: usb 4-2: USB disconnect,
> device number 20
>
> This has to be a timer somewhere in the USB software in the mice or
> the kernel, doesn't it?
Indeed.
You said the problems began on one of the computers when you upgraded
the kernel. Can you try using bisection to find the kernel change that
first triggered the problem?
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
