From owner-freebsd-stable@FreeBSD.ORG Fri Feb 8 16:07:53 2008 Return-Path: Delivered-To: stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 8092616A420; Fri, 8 Feb 2008 16:07:53 +0000 (UTC) (envelope-from ws@au.dyndns.ws) Received: from ipmail05.adl2.internode.on.net (ipmail05.adl2.internode.on.net [203.16.214.145]) by mx1.freebsd.org (Postfix) with ESMTP id 32FB213C458; Fri, 8 Feb 2008 16:07:51 +0000 (UTC) (envelope-from ws@au.dyndns.ws) X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: AgAAAJoKrEeWZWdv/2dsb2JhbAAIrBs X-IronPort-AV: E=Sophos;i="4.25,322,1199626200"; d="scan'208";a="50779739" Received: from ppp103-111.static.internode.on.net (HELO [192.168.1.131]) ([150.101.103.111]) by ipmail05.adl2.internode.on.net with ESMTP; 09 Feb 2008 02:37:50 +1030 From: Wayne Sierke To: Jeremy Chadwick In-Reply-To: <1201918236.5350.47.camel@predator-ii.buffyverse> References: <1201188590.2075.4.camel@predator-ii.buffyverse> <1201865411.5350.12.camel@predator-ii.buffyverse> <20080201151750.GA62488@eos.sc1.parodius.com> <1201918236.5350.47.camel@predator-ii.buffyverse> Content-Type: text/plain Date: Sat, 09 Feb 2008 02:37:45 +1030 Message-Id: <1202486866.1535.103.camel@predator-ii.buffyverse> Mime-Version: 1.0 X-Mailer: Evolution 2.12.3 FreeBSD GNOME Team Port Content-Transfer-Encoding: 7bit Cc: stable@freebsd.org Subject: Re: Frequent USB mouse disconnections under load with RELENG_7] X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 08 Feb 2008 16:07:53 -0000 Curiouser and curiouser... Synopsis: attaching either or both of two Logitech MX500 mice directly to the (fixed) rear USB ports on this system results in frequent disconnections (disconnect/reconnects) of the mice (ums0/ums1). The frequency of the disconnections apparently increases under increased cpu load. A mouse attached via a second (expansion) pair of USB ports, taken from a header on the motherboard, results in no disconnections for that mouse. Interposing a 4-port USB hub between a mouse and the fixed rear USB ports results in no disconnections for that mouse - with the exception that attaching an FTDI serial adapter to the 4-port hub results in a single disconnection event, but the same symptom is not produced by attaching other assorted USB devices to the hub. Additionally, the disconnection so induced sometimes doesn't include a re-attach event for the mouse (i.e. it remains disconnected until physically detached then reattached). Now the details: After upgrading this system (i386) from RELENG_6 (6.3-PRERELEASE) to RELENG_7 (GENERIC) I started experiencing frequent disconnections with my Logitech USB MX500 mouse. After posting about it on -stable the only idea arrived at was to try removing the extant moused configuration from rc.conf, a remnant from previous configurations. What follows is the outcome of trying that and subsequent investigations. Removing moused_* from rc.conf didn't have any discernible effect other than eliminating the error from moused as seen in /var/log/messages. The disconnects still occur and I've done a little experimentation which has provided some interesting further info. This board (a Gigabyte 8SQ800) has two fixed USB ports on the rear connectors and four additional ports available via a pair of headers, one of which is currently fitted with a rear-panel expansion plate making two more ports accessible for a total of four out of the six supported by the board. kernel: ohci0: mem 0xfb001000-0xfb001fff irq 20 at device 3.0 on pci0 kernel: ohci0: [GIANT-LOCKED] kernel: ohci0: [ITHREAD] kernel: usb0: OHCI version 1.0, legacy support kernel: usb0: on ohci0 kernel: usb0: USB revision 1.0 kernel: uhub0: on usb0 kernel: uhub0: 2 ports with 2 removable, self powered kernel: ohci1: mem 0xfb002000-0xfb002fff irq 21 at device 3.1 on pci0 kernel: ohci1: [GIANT-LOCKED] kernel: ohci1: [ITHREAD] kernel: usb1: OHCI version 1.0, legacy support kernel: usb1: on ohci1 kernel: usb1: USB revision 1.0 kernel: uhub1: on usb1 kernel: uhub1: 2 ports with 2 removable, self powered kernel: ohci2: mem 0xfb003000-0xfb003fff irq 22 at device 3.2 on pci0 kernel: ohci2: [GIANT-LOCKED] kernel: ohci2: [ITHREAD] kernel: usb2: OHCI version 1.0, legacy support kernel: usb2: on ohci2 kernel: usb2: USB revision 1.0 kernel: uhub2: on usb2 kernel: uhub2: 2 ports with 2 removable, self powered kernel: ehci0: mem 0xfb004000-0xfb004fff irq 23 at device 3.3 on pci0 kernel: ehci0: [GIANT-LOCKED] kernel: ehci0: [ITHREAD] kernel: usb3: EHCI version 1.0 kernel: usb3: companion controllers, 2 ports each: usb0 usb1 usb2 kernel: usb3: on ehci0 kernel: usb3: USB revision 2.0 kernel: uhub3: on usb3 kernel: uhub3: 6 ports with 6 removable, self powered The original MX500 mouse was attached to usb0/port 1. I added a second MX500 mouse (same model, different revision) attached to usb0/port 2. root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub0 kernel: ums0: on uhub0 kernel: ums0: 8 buttons and Z dir. root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub0 kernel: ums1: on uhub0 kernel: ums1: 8 buttons and Z dir. It wasn't long before I experienced disconnections with both mice! kernel: ums1: at uhub0 port 2 (addr 3) disconnected kernel: ums1: detached root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub0 kernel: ums1: on uhub0 kernel: ums1: 8 buttons and Z dir. kernel: ums0: at uhub0 port 1 (addr 2) disconnected kernel: ums0: detached root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub0 kernel: ums0: on uhub0 kernel: ums0: 8 buttons and Z dir. # cat /var/log/messages | grep 'ums0: detached$' | wc -l 63 # cat /var/log/messages | grep 'ums1: detached$' | wc -l 49 I then attached both mice to the expansion USB ports. The disconnections ceased. One of the mice was then swapped back to the fixed USB ports. That mouse suffered disconnections while the mouse attached to the expansion port did not. It seemed that perhaps the fixed USB ports might be faulty. To further investigate that possibility I attached a 4-port USB hub to usb0: kernel: uhub4: on uhub0 kernel: uhub4: 4 ports with 4 removable, self powered and attached one of the mice to it: root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub4 kernel: ums1: on uhub4 kernel: ums1: 8 buttons and Z dir. that mouse didn't experience any subsequent disconnections. With one exception, when I attached to the hub a USB serial adapter that happened to be at hand: kernel: ums0: at uhub4 port 1 (addr 3) disconnected kernel: ums0: detached root: Unknown USB device: vendor 0x0403 product 0x6001 bus uhub4 kernel: ugen0: on uhub4 root: Unknown USB device: vendor 0x046d product 0xc025 bus uhub4 kernel: ums0: on uhub4 kernel: ums0: 8 buttons and Z dir. which turned out to be repeatable. It was subsequently observed that sometimes the mouse wouldn't re-attach and had to be physically detached and reattached. With both mice attached to the hub, attaching the FTDI adapter seemed to result in both mice detaching, and only one re-attaching. Moving the hub from one of the fixed rear ports to one of the expansion ports doesn't change this behaviour - subsequently attaching the FTDI device still results in the mouse (or both mice) detaching and only sometimes re-attaching. Attaching a couple of other devices to the hub (a USB flash drive, a bluetooth adapter) has not so far resulted in disconnection for the mouse/mice that are also attached to the hub. In summary: - mice attached directly to either of the fixed USB ports suffer frequent disconnect/reconnect events and affected by cpu load - mice attached via the expansion USB ports do not suffer disconnections of themselves even when attached to the fixed USB ports - introducing a usb hub between one or both mice and the fixed USB ports eliminates the disconnections for the mouse/mice attached to the hub, but not for a mouse attached directly to a fixed USB port - mice attached to the hub experience disconnects when a particular device is subsequently attached to the hub, apparently remaining unaffected by other assorted devices being attached to the hub, and regardless of which USB port the hub is attached to *phew* Any suggestions as to how to set about tracking this down are most welcome. Should I take this to -USB? In the course of this testing the system also suffered a panic, as best as I can tell from unplugging one of the "other" USB devices. I'll raise this again with specifics if I can reproduce it. I also conducted an admittedly brief test with a Knoppix (v5.0.1) CD during which I was unable to reproduce any of these symptoms. # usbdevs -v Controller /dev/usb0: addr 1: full speed, self powered, config 1, OHCI root hub(0x0000), SiS(0x0000), rev 1.00 port 1 addr 2: low speed, power 98 mA, config 1, USB-PS/2 Optical Mouse(0xc025), Logitech(0x046d), rev 18.00 port 2 addr 3: full speed, self powered, config 1, product 0x0902(0x0902), vendor 0x03eb(0x03eb), rev 1.00 port 1 addr 4: full speed, power 90 mA, config 1, TTL232R(0x6001), FTDI(0x0403), rev 6.00 port 2 addr 5: low speed, power 98 mA, config 1, USB-PS/2 Optical Mouse(0xc025), B16_b_02(0x046d), rev 98.02 port 3 addr 6: full speed, power 100 mA, config 1, USB Mass Storage Device(0x4146), USB Disk(0x4146), rev 1.00 port 4 addr 7: full speed, power 100 mA, config 1, BCM2045B2(0x4500), Broadcom(0x0a5c), rev 1.00 port 1 addr 8: full speed, self powered, config 1, BCM92045DG-Flash_UHE(0x2100), Broadcom Corp(0x0a5c), rev 1.00 port 2 addr 9: full speed, self powered, config 1, BCM92045DG-Flash_UHE(0x4502), Broadcom Corp(0x0a5c), rev 1.00 port 3 addr 10: full speed, self powered, config 1, BCM92045DG-Flash_UHE(0x4503), Broadcom Corp(0x0a5c), rev 1.00 Controller /dev/usb1: addr 1: full speed, self powered, config 1, OHCI root hub(0x0000), SiS(0x0000), rev 1.00 port 1 powered port 2 powered Controller /dev/usb2: addr 1: full speed, self powered, config 1, OHCI root hub(0x0000), SiS(0x0000), rev 1.00 port 1 powered port 2 powered Controller /dev/usb3: addr 1: high speed, self powered, config 1, EHCI root hub(0x0000), SiS(0x0000), rev 1.00 port 1 powered port 2 powered port 3 powered port 4 powered port 5 powered port 6 powered # pciconf -lv hostb0@pci0:0:0:0: class=0x060000 card=0x06551039 chip=0x06551039 rev=0x10 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS655 Host-to-PCI Bridge' class = bridge subclass = HOST-PCI pcib1@pci0:0:1:0: class=0x060400 card=0x00000000 chip=0x00021039 rev=0x00 hdr=0x01 vendor = 'Silicon Integrated Systems (SiS)' device = '6202 Virtual PCI to PCI Bridge (AGP)' class = bridge subclass = PCI-PCI isab0@pci0:0:2:0: class=0x060100 card=0x00000000 chip=0x00081039 rev=0x04 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS PCI to ISA Bridge (LPC Bridge)' class = bridge subclass = PCI-ISA fwohci0@pci0:0:2:3: class=0x0c0010 card=0x13941039 chip=0x70071039 rev=0x00 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS OHCI Compliant FireWire Controller' class = serial bus subclass = FireWire atapci0@pci0:0:2:5: class=0x010180 card=0x55131039 chip=0x55131039 rev=0x00 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS5513 EIDE Controller (A,B step)' class = mass storage subclass = ATA pcm0@pci0:0:2:7: class=0x040100 card=0xa0021458 chip=0x70121039 rev=0xa0 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS7012 PCI Audio Accelerator' class = multimedia subclass = audio ohci0@pci0:0:3:0: class=0x0c0310 card=0x70011039 chip=0x70011039 rev=0x0f hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS5597/8 Universal Serial Bus Controller' class = serial bus subclass = USB ohci1@pci0:0:3:1: class=0x0c0310 card=0x70011039 chip=0x70011039 rev=0x0f hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS5597/8 Universal Serial Bus Controller' class = serial bus subclass = USB ohci2@pci0:0:3:2: class=0x0c0310 card=0x70011039 chip=0x70011039 rev=0x0f hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS5597/8 Universal Serial Bus Controller' class = serial bus subclass = USB ehci0@pci0:0:3:3: class=0x0c0320 card=0x50041458 chip=0x70021039 rev=0x00 hdr=0x00 vendor = 'Silicon Integrated Systems (SiS)' device = 'SiS7002 USB 2.0 Enhanced Host Controller' class = serial bus subclass = USB ahc0@pci0:0:10:0: class=0x010000 card=0x00000000 chip=0x71789004 rev=0x03 hdr=0x00 vendor = 'Adaptec Inc' device = 'AHA-2940/2940W Fast/Fast-Wide SCSI Ctrlr' class = mass storage subclass = SCSI rl0@pci0:0:11:0: class=0x020000 card=0x13031186 chip=0x13001186 rev=0x10 hdr=0x00 vendor = 'D-Link System Inc' device = 'DL 10038C or 10038D (Remark of Realtek RTL-8139) Fast Ethernet Adapter' class = network subclass = ethernet nvidia0@pci0:1:0:0: class=0x030000 card=0x809f1043 chip=0x017110de rev=0xa3 hdr=0x00 vendor = 'Nvidia Corp' device = 'GeForce4 MX 440 [NV17.2]' class = display subclass = VGA # vmstat -ai interrupt total rate ??? 0 0 irq1: atkbd0 25536 4 stray irq1 0 0 irq0: 0 0 stray irq0 0 0 irq3: sio1 0 0 stray irq3 0 0 irq4: sio0 0 0 stray irq4 0 0 irq5: 0 0 stray irq5 0 0 irq6: fdc0 10 0 stray irq6 0 0 irq7: ppbus0 ppc0 0 0 stray irq7 0 0 irq8: 0 0 stray irq8 0 0 irq9: acpi0 0 0 stray irq9 0 0 irq10: 0 0 stray irq10 0 0 irq11: 0 0 stray irq11 0 0 irq12: 0 0 stray irq12 0 0 irq13: 0 0 stray irq13 0 0 irq14: ata0 16546 2 stray irq14 0 0 irq15: ata1 45670 7 stray irq15 0 0 irq16: nvidia0 334184 53 stray irq16 0 0 irq17: fwohci0 3 0 stray irq17 0 0 irq18: pcm0 ahc0 540635 86 stray irq18 0 0 irq19: rl0 8115 1 stray irq19 0 0 irq20: ohci0 892174 143 stray irq20 0 0 irq21: ohci1 120905 19 stray irq21 0 0 irq22: ohci2 0 0 stray irq22 0 0 irq23: ehci0 7 0 stray irq23 0 0 cpu0: timer 12441509 1999 Total 14425294 2318 Thanks, Wayne