From owner-freebsd-bugs Sun Mar 10 19:20:12 2002 Delivered-To: freebsd-bugs@hub.freebsd.org Received: from freefall.freebsd.org (freefall.FreeBSD.org [216.136.204.21]) by hub.freebsd.org (Postfix) with ESMTP id 96D6037B416 for ; Sun, 10 Mar 2002 19:20:00 -0800 (PST) Received: (from gnats@localhost) by freefall.freebsd.org (8.11.6/8.11.6) id g2B3K0E47478; Sun, 10 Mar 2002 19:20:00 -0800 (PST) (envelope-from gnats) Received: from topaz.mdcc.cx (topaz.mdcc.cx [212.204.230.141]) by hub.freebsd.org (Postfix) with ESMTP id 5AC2537B419 for ; Sun, 10 Mar 2002 19:17:42 -0800 (PST) Received: from k7.mavetju.org (topaz.mdcc.cx [212.204.230.141]) by topaz.mdcc.cx (Postfix) with ESMTP id 28BCC2B671 for ; Mon, 11 Mar 2002 04:17:36 +0100 (CET) Received: by k7.mavetju.org (Postfix, from userid 1001) id EA405302; Mon, 11 Mar 2002 14:17:31 +1100 (EST) Message-Id: <20020311031731.EA405302@k7.mavetju.org> Date: Mon, 11 Mar 2002 14:17:31 +1100 (EST) From: Edwin Groothuis Reply-To: Edwin Groothuis To: FreeBSD-gnats-submit@freebsd.org X-Send-Pr-Version: 3.113 Subject: kern/35756: USB reattach of Sony DSC-S75 fails, USB subsystem hangs Sender: owner-freebsd-bugs@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.org >Number: 35756 >Category: kern >Synopsis: USB reattach of Sony DSC-S75 fails, USB subsystem hangs >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sun Mar 10 19:20:00 PST 2002 >Closed-Date: >Last-Modified: >Originator: Edwin Groothuis >Release: FreeBSD 4.5-RELEASE i386 >Organization: - >Environment: System: FreeBSD k7.mavetju.org 4.5-RELEASE FreeBSD 4.5-RELEASE #3: Mon Mar 11 13:32:05 EST 2002 edwin@k7.mavetju.org:/usr/src/sys/compile/k7 i386 >Description: With a Sony DSC-S75 digital camera, if I turn it on while being connected to my computer, it is recognized perfectly, I can mount /dev/da0 and fetch the pictures. Unmount and turn it off, the da0 device disappears. But when I turn it on again, the da0 device doesn't come back and the USB subsystem hangs: 162 root -6 0 908K 532K usbsyn 0:00 0.00% 0.00% usbd I have the output of several logs: /var/log/messages (USB_DEBUG and UMASS_DEBUG), usbd -d -v -v -v and usbdevs -v Before the action: usbdevs -v: Controller /dev/usb0: addr 1: self powered, config 1, OHCI root hub(0x0000), AMD(0x0000), rev 0x0100 port 1 powered port 2 powered port 3 powered port 4 powered usbd -v -v -v -d usbd: opened /dev/usb0 usbd: reading configuration file /etc/usbd.conf usbd: action 1: ActiveWire board, firmware download vndr=0x0854 prdct=0x0100 rlse=0x0000 attach='/usr/local/bin/ezdownload -f /usr/local/share/usb/firmware/0854.0100.0_01.hex ${DEVNAME}' usbd: action 2: Entrega Serial with UART vndr=0x1645 prdct=0x8001 rlse=0x0101 attach='/usr/sbin/ezdownload -v -f /usr/share/usb/firmware/1645.8001.0101 /dev/${DEVNAME}' usbd: action 3: USB ethernet devname: [ack]ue[0-9]+ attach='dhclient ${DEVNAME}' detach='killall dhclient' usbd: action 4: Mouse devname: ums[0-9]+ attach='/usr/sbin/moused -p /dev/${DEVNAME} -I /var/run/moused.${DEVNAME}.pid' usbd: action 5: USB device usbd: 5 actions usbd: opened /dev/usb Just after the camera is switched on: usbd -v -v -v -d: usbd: doing discovery on /dev/usb0 usbd: processing event queue on /dev/usb usbd: attach event at 1015813036.504718000, Sony DSC, Sony: vndr=0x054c prdct=0x0010 rlse=0x0322 clss=0x0000 subclss=0x0000 prtcl=0x0000 device names: umass0 usbd: Found action 'USB device' for Sony DSC, Sony at umass0 usbd: action 0: USB device usbd: Setting DEVNAME='umass0' /var/log/messages: Mar 11 13:11:23 k7 /kernel: umass0: Sony Sony DSC, rev 1.00/3.22, addr 2, RBC over CBI Mar 11 13:11:23 k7 /kernel: umass-sim:0:-1:-1:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:-1: Attached to scbus0 as device 0 Mar 11 13:11:23 k7 /kernel: scbus0: scanning for umass0:0:0:-1 Mar 11 13:11:23 k7 /kernel: umass-sim:0:-1:-1:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_SCSI_IO: cmd: 0x12, flags: 0x40, 6b cmd/36b data/18b sense Mar 11 13:11:23 k7 /kernel: umass-sim:0:1:0:func_code 0x0004: Invalid target (no wildcard) Mar 11 13:11:23 k7 /kernel: umass-sim:0:2:0:func_code 0x0004: Invalid target (no wildcard) Mar 11 13:11:23 k7 /kernel: umass0: Attach finished Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 008000011f000000536f6e7920202020 buffer=0xc1881684, buflen=36 Mar 11 13:11:23 k7 /kernel: umass0: 0x 536f6e79204453432020202020202020 Mar 11 13:11:23 k7 /kernel: umass0: 0x 332e3232 Mar 11 13:11:23 k7 /kernel: umass0: Fetching 0b sense data Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 700000000000000a0000000000000000 buffer=0xc188d470, buflen=18 Mar 11 13:11:23 k7 /kernel: umass0: 0x 0000 Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_SCSI_IO: cmd: 0x12, flags: 0x40, 6b cmd/255b data/18b sense Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 008000011f000000536f6e7920202020 buffer=0xc1883500, buflen=72 Mar 11 13:11:23 k7 /kernel: umass0: 0x 536f6e79204453432020202020202020 Mar 11 13:11:23 k7 /kernel: umass0: 0x 332e3232008000011f000000536f6e79 ... Mar 11 13:11:23 k7 /kernel: umass0: Fetching 18b sense data Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 700000000000000a0000000000000000 buffer=0xc188d470, buflen=18 Mar 11 13:11:23 k7 /kernel: umass0: 0x 0000 Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_GET_TRAN_SETTINGS:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_GET_TRAN_SETTINGS:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_SET_TRAN_SETTINGS:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_SCSI_IO: cmd: 0x00, flags: 0xc0, 6b cmd/0b data/32b sense Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: no data phase Mar 11 13:11:23 k7 /kernel: umass0: Fetching 18b sense data Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 700000000000000a0000000000000000 buffer=0xc188d470, buflen=18 Mar 11 13:11:23 k7 /kernel: umass0: 0x 0000 Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_SCSI_IO: cmd: 0x25, flags: 0x40, 10b cmd/8b data/32b sense Mar 11 13:11:23 k7 /kernel: scbus0: Rescan succeeded Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 00003ddf00000200 buffer=0xc15b6020, buflen=8 Mar 11 13:11:23 k7 /kernel: umass0: Fetching 32b sense data Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc15b9f80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887b80, NORMAL_COMPLETION Mar 11 13:11:23 k7 /kernel: umass0: 0x 700000000000000a0000000000000000 buffer=0xc188d470, buflen=18 Mar 11 13:11:23 k7 /kernel: umass0: 0x 0000 Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_CALC_GEOMETRY: Volume size = 15840 Mar 11 13:11:23 k7 /kernel: da0 at umass-sim0 bus 0 target 0 lun 0 Mar 11 13:11:23 k7 /kernel: da0: Removable Direct Access SCSI-0 device Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_GET_TRAN_SETTINGS:. Mar 11 13:11:23 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:11:23 k7 /kernel: da0: 150KB/s transfers Mar 11 13:11:23 k7 /kernel: da0: 7MB (15840 512 byte sectors: 0H 0S/T 0C) usbdevs -v Controller /dev/usb0: addr 1: self powered, config 1, OHCI root hub(0x0000), AMD(0x0000), rev 0x0100 port 1 addr 2: self powered, config 1, Sony DSC(0x0010), Sony(0x054c), rev 0x03 22 port 2 powered port 3 powered port 4 powered Then I turn off the camera: usbd -v -v -v -d: usbd: doing discovery on /dev/usb0 usbd: processing event queue on /dev/usb usbd: detach event at 1015813065.239581000, DSC cameras, Sony Corp.: vndr=0x054c prdct=0x0010 rlse=0x0322 clss=0x0000 subclss=0x0000 prtcl=0x0000 device names: umass0 usbd: Found action 'USB device' for DSC cameras, Sony Corp. at umass0 usbd: action 0: USB device usbd: Setting DEVNAME='umass0' /var/log/messages Mar 11 13:12:12 k7 /kernel: umass0: at uhub0 port 1 (addr 2) disconnected Mar 11 13:12:12 k7 /kernel: umass0: detached Mar 11 13:12:12 k7 /kernel: umass0:0:0:-1: losing CAM device entry Mar 11 13:12:12 k7 /kernel: (da0:umass-sim0:0:0:0): lost device Mar 11 13:12:12 k7 /kernel: (da0:umass-sim0:0:0:0): removing device entry Mar 11 13:12:12 k7 /kernel: umass0: detached usbdevs -v Controller /dev/usb0: addr 1: self powered, config 1, OHCI root hub(0x0000), AMD(0x0000), rev 0x0100 port 1 powered port 2 powered port 3 powered port 4 powered And turned it on again: usbd -v -v -v -d: usbd: doing discovery on /dev/usb0 [hangs in call to ioctl while doing discovery on /dev/usb0] /var/log/messages Mar 11 13:12:50 k7 /kernel: umass0: Sony Sony DSC, rev 1.00/3.22, addr 2, RBC over CBI Mar 11 13:12:50 k7 /kernel: umass0:0:0:-1: Attached to scbus0 as device 0 Mar 11 13:12:50 k7 /kernel: scbus0: scanning for umass0:0:0:-1 Mar 11 13:12:50 k7 /kernel: umass-sim:0:-1:-1:XPT_PATH_INQ:. Mar 11 13:12:50 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:12:50 k7 /kernel: umass0:0:0:0:XPT_PATH_INQ:. Mar 11 13:12:50 k7 /kernel: umass0:0:0:0:XPT_SCSI_IO: cmd: 0x12, flags: 0x40, 6b cmd/36b data/18b sense Mar 11 13:12:50 k7 /kernel: umass-sim:0:1:0:func_code 0x0004: Invalid target (no wildcard) Mar 11 13:12:50 k7 /kernel: umass-sim:0:2:0:func_code 0x0004: Invalid target (no wildcard) Mar 11 13:12:50 k7 /kernel: umass0: Attach finished Mar 11 13:12:50 k7 /kernel: umass0: Handling CBI state 10 (CBI Command), xfer=0xc1887800, NORMAL_COMPLETION Mar 11 13:12:50 k7 /kernel: umass0: Handling CBI state 11 (CBI Data), xfer=0xc1887880, NORMAL_COMPLETION Mar 11 13:12:50 k7 /kernel: umass0: 0x 008000011f000000536f6e7920202020 buffer=0xc1881284, buflen=36 Mar 11 13:12:50 k7 /kernel: umass0: 0x 536f6e79204453432020202020202020 Mar 11 13:12:50 k7 /kernel: umass0: 0x 332e3232 Mar 11 13:12:50 k7 /kernel: umass0: Fetching 0b sense data usbdevs -v Controller /dev/usb0: addr 1: self powered, config 1, OHCI root hub(0x0000), AMD(0x0000), rev 0x0100 [hangs in usbsyn state] >How-To-Repeat: >Fix: workaround: reboot machine before reattaching camera :-( If there are patches to be tried, more tests to be done etc, I'm available for it. I've looked through usb.c but unfortunatly it's too USB-technical for me. >Release-Note: >Audit-Trail: >Unformatted: To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-bugs" in the body of the message