udev hangs USB camera/resets USB

Bug #180472 reported by Grant Grundler on 2008-01-05
4
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Undecided
Unassigned

Bug Description

Binary package hint: linux-image-2.6.22-14-generic

From: Grant Grundler <email address hidden>
To: Ubuntu Bug Tracking System <email address hidden>
From: Grant Grundler <email address hidden>
Cc: Grant Grundler <email address hidden>
Subject: /usr/sbin/hald: hald confuses HP R707 camera in USB-Storage mode
Message-ID: <email address hidden>
X-Mailer: reportbug 3.38ubuntu2
Date: Fri, 04 Jan 2008 17:15:33 -0800

Package: hal
Version: 0.5.9.1-6ubuntu5
Severity: normal
File: /usr/sbin/hald

hald was crashing the HP R707 camera that was set in "USB Storage" mode.
Stopping hald (/etc/init.d/hal stop) allowed me to
        dd if=/dev/sdb1 of=tmpfile

the entire 256MB SD card. (I initially tried with 32MB SD card in the
camera as output below will show).

If I connect the device while hald is running, I get the follow dmesg
output. Eveything is good up to "Attached scsi generic sg1 type 0"
output. "reset" is because hald is doing something and results in the
deivce going "offline". As noted above, stopping hald allows me to read
from the device.

[877591.083986] usb 1-1.1.2: new full speed USB device using uhci_hcd and address 53
[877591.206165] usb 1-1.1.2: configuration #1 chosen from 1 choice
[877591.209825] scsi13 : SCSI emulation for USB Mass Storage devices
[877591.210670] usb-storage: device found at 53
[877591.210679] usb-storage: waiting for device to settle before scanning
[877596.207195] usb-storage: device scan complete
[877596.210222] scsi scan: INQUIRY result too short (5), using 36
[877596.210244] scsi 13:0:0:0: Direct-Access HP PhotoSmart R707 A001 PQ: 0 ANSI: 0
[877596.217133] sd 13:0:0:0: [sdb] 60801 512-byte hardware sectors (31 MB)
[877596.220127] sd 13:0:0:0: [sdb] Write Protect is off
[877596.220143] sd 13:0:0:0: [sdb] Mode Sense: 0f 00 00 00
[877596.220151] sd 13:0:0:0: [sdb] Assuming drive cache: write through
[877596.229117] sd 13:0:0:0: [sdb] 60801 512-byte hardware sectors (31 MB)
[877596.232122] sd 13:0:0:0: [sdb] Write Protect is off
[877596.232137] sd 13:0:0:0: [sdb] Mode Sense: 0f 00 00 00
[877596.232144] sd 13:0:0:0: [sdb] Assuming drive cache: write through
[877596.232155] sdb: sdb1
[877596.242212] sd 13:0:0:0: [sdb] Attached SCSI removable disk
[877596.242325] sd 13:0:0:0: Attached scsi generic sg1 type 0
[877626.715068] usb 1-1.1.2: reset full speed USB device using uhci_hcd and address 53
[877636.889376] usb 1-1.1.2: reset full speed USB device using uhci_hcd and address 53
[877642.064490] usb 1-1.1.2: reset full speed USB device using uhci_hcd and address 53
[877652.239811] usb 1-1.1.2: reset full speed USB device using uhci_hcd and address 53
[877652.347289] sd 13:0:0:0: scsi: Device offlined - not ready after error recovery
[877652.347316] sd 13:0:0:0: [sdb] Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK,SUGGEST_OK
[877652.347329] end_request: I/O error, dev sdb, sector 60800
[877652.347340] Buffer I/O error on device sdb, logical block 60800
[877652.353107] sd 13:0:0:0: rejecting I/O to offline device
[877652.353131] Buffer I/O error on device sdb, logical block 60800
[877652.353585] sd 13:0:0:0: rejecting I/O to offline device
[877652.353596] Buffer I/O error on device sdb, logical block 60792
[877652.353974] sd 13:0:0:0: rejecting I/O to offline device
[877652.353984] Buffer I/O error on device sdb, logical block 60793
[877652.354360] sd 13:0:0:0: rejecting I/O to offline device
[877652.354370] Buffer I/O error on device sdb, logical block 60794
[877652.354747] sd 13:0:0:0: rejecting I/O to offline device
[877652.354757] Buffer I/O error on device sdb, logical block 60795
[877652.355191] sd 13:0:0:0: rejecting I/O to offline device
[877652.355202] Buffer I/O error on device sdb, logical block 60796
[877652.355578] sd 13:0:0:0: rejecting I/O to offline device
[877652.355588] Buffer I/O error on device sdb, logical block 60797
[877652.355964] sd 13:0:0:0: rejecting I/O to offline device
[877652.355975] Buffer I/O error on device sdb, logical block 60798
[877652.356350] sd 13:0:0:0: rejecting I/O to offline device
[877652.356360] Buffer I/O error on device sdb, logical block 60799
[877652.356741] sd 13:0:0:0: rejecting I/O to offline device
[877652.356933] sd 13:0:0:0: rejecting I/O to offline device
[877652.357126] sd 13:0:0:0: rejecting I/O to offline device
[877652.357320] sd 13:0:0:0: rejecting I/O to offline device
[877652.357514] sd 13:0:0:0: rejecting I/O to offline device
[877652.357706] sd 13:0:0:0: rejecting I/O to offline device
[877652.357899] sd 13:0:0:0: rejecting I/O to offline device
[877652.358093] sd 13:0:0:0: rejecting I/O to offline device
[877652.358304] sd 13:0:0:0: rejecting I/O to offline device
[877652.358511] sd 13:0:0:0: rejecting I/O to offline device
[877652.358720] sd 13:0:0:0: rejecting I/O to offline device
[877652.358964] sd 13:0:0:0: rejecting I/O to offline device
[877652.359158] sd 13:0:0:0: rejecting I/O to offline device
[877652.359351] sd 13:0:0:0: rejecting I/O to offline device
[877652.359543] sd 13:0:0:0: rejecting I/O to offline device
[877652.359737] sd 13:0:0:0: rejecting I/O to offline device
[877652.359931] sd 13:0:0:0: rejecting I/O to offline device
[877652.360124] sd 13:0:0:0: rejecting I/O to offline device
[877652.360316] sd 13:0:0:0: rejecting I/O to offline device
[877652.360533] sd 13:0:0:0: rejecting I/O to offline device
[877652.360728] sd 13:0:0:0: rejecting I/O to offline device
[877652.360921] sd 13:0:0:0: rejecting I/O to offline device
[877652.361114] sd 13:0:0:0: rejecting I/O to offline device
[877652.361307] sd 13:0:0:0: rejecting I/O to offline device
[877652.361500] sd 13:0:0:0: rejecting I/O to offline device
[877652.361693] sd 13:0:0:0: rejecting I/O to offline device
[877652.361887] sd 13:0:0:0: rejecting I/O to offline device
[877652.362110] sd 13:0:0:0: rejecting I/O to offline device
[877652.362319] sd 13:0:0:0: rejecting I/O to offline device
[877652.362762] sd 13:0:0:0: rejecting I/O to offline device
[877652.364393] sd 13:0:0:0: rejecting I/O to offline device
[877652.364621] sd 13:0:0:0: rejecting I/O to offline device
[877652.364814] sd 13:0:0:0: rejecting I/O to offline device
[877652.365008] sd 13:0:0:0: rejecting I/O to offline device
[877652.365202] sd 13:0:0:0: rejecting I/O to offline device
[877652.365395] sd 13:0:0:0: rejecting I/O to offline device
[877652.365588] sd 13:0:0:0: rejecting I/O to offline device
[877652.365904] sd 13:0:0:0: rejecting I/O to offline device
[877652.366099] sd 13:0:0:0: rejecting I/O to offline device
[877652.366293] sd 13:0:0:0: rejecting I/O to offline device
[877652.366486] sd 13:0:0:0: rejecting I/O to offline device
[877652.366684] sd 13:0:0:0: rejecting I/O to offline device
[877652.367094] sd 13:0:0:0: rejecting I/O to offline device
[877652.367291] sd 13:0:0:0: rejecting I/O to offline device
[877652.367485] sd 13:0:0:0: rejecting I/O to offline device
[877652.367728] sd 13:0:0:0: rejecting I/O to offline device
[877652.367924] sd 13:0:0:0: rejecting I/O to offline device
[877652.368118] sd 13:0:0:0: rejecting I/O to offline device
[877652.368312] sd 13:0:0:0: rejecting I/O to offline device
[877652.368507] sd 13:0:0:0: rejecting I/O to offline device
[877652.368701] sd 13:0:0:0: rejecting I/O to offline device
[877652.368895] sd 13:0:0:0: rejecting I/O to offline device
[877652.369089] sd 13:0:0:0: rejecting I/O to offline device
[877652.369315] sd 13:0:0:0: rejecting I/O to offline device
[877652.369511] sd 13:0:0:0: rejecting I/O to offline device
[877652.369706] sd 13:0:0:0: rejecting I/O to offline device
[877652.369900] sd 13:0:0:0: rejecting I/O to offline device
[877652.370094] sd 13:0:0:0: rejecting I/O to offline device
[877652.370289] sd 13:0:0:0: rejecting I/O to offline device
[877652.370483] sd 13:0:0:0: rejecting I/O to offline device
[877652.370677] sd 13:0:0:0: rejecting I/O to offline device
[877652.370971] sd 13:0:0:0: rejecting I/O to offline device
[877652.371168] sd 13:0:0:0: rejecting I/O to offline device
[877652.371362] sd 13:0:0:0: rejecting I/O to offline device
[877652.371557] sd 13:0:0:0: rejecting I/O to offline device
[877652.371751] sd 13:0:0:0: rejecting I/O to offline device
[877652.371945] sd 13:0:0:0: rejecting I/O to offline device
[877652.372139] sd 13:0:0:0: rejecting I/O to offline device
[877652.372334] sd 13:0:0:0: rejecting I/O to offline device

I don't know which command hald is sending that is causing the
problems but I expect with strace I can figure out which one
takes a long time to complete and fails.

I had stopped udev and this had the original /dev/sdb1 present.
I restarted udev and reconnected the camera:
[884994.620480] usb-storage: device scan complete
[884994.624471] scsi scan: INQUIRY result too short (5), using 36
[884994.624490] scsi 23:0:0:0: Direct-Access HP PhotoSmart
R707 A001 PQ: 0 ANSI: 0
[884994.634410] sd 23:0:0:0: [sdb] 494081 512-byte hardware sectors (253
MB)
[884994.637405] sd 23:0:0:0: [sdb] Write Protect is off
[884994.637418] sd 23:0:0:0: [sdb] Mode Sense: 0f 00 00 00
[884994.637426] sd 23:0:0:0: [sdb] Assuming drive cache: write through
[884994.648428] sd 23:0:0:0: [sdb] 494081 512-byte hardware sectors (253
MB)
[884994.651437] sd 23:0:0:0: [sdb] Write Protect is off
[884994.651453] sd 23:0:0:0: [sdb] Mode Sense: 0f 00 00 00
[884994.651461] sd 23:0:0:0: [sdb] Assuming drive cache: write through
[884994.651472] sdb: sdb1
[884994.661489] sd 23:0:0:0: [sdb] Attached SCSI removable disk
[884994.661604] sd 23:0:0:0: Attached scsi generic sg1 type 0

and /dev/sdb* shows:
root@mb500:/etc/udev/rules.d # ls -l /dev/sdb*
brw-rw---- 1 root plugdev 8, 16 2008-01-04 17:13 /dev/sdb
brw-rw---- 1 root plugdev 8, 17 2008-01-04 17:13 /dev/sdb1

and I conclude udev is working correctly.

grundler@mb500:~$ cat /proc/partitions
major minor #blocks name

   8 0 58605120 sda
   8 1 12287992 sda1
   8 2 1048824 sda2
   8 3 8388576 sda3
   8 4 36879696 sda4
   8 16 247040 sdb
   8 17 246989 sdb1

BTW, this is an "Ubuntu Gutsy" system despite what "reportbug" thinks.
Contents of sources.list:

#deb http://us.archive.ubuntu.com/ubuntu hardy main restricted universe multiverse
#deb-src http://us.archive.ubuntu.com/ubuntu hardy main restricted universe multiverse
#deb http://security.ubuntu.com/ubuntu hardy-security main restricted universe
#deb-src http://security.ubuntu.com/ubuntu hardy-security main restricted universe

deb http://us.archive.ubuntu.com/ubuntu gutsy main restricted universe multiverse
deb-src http://us.archive.ubuntu.com/ubuntu gutsy main restricted universe multiverse
deb http://security.ubuntu.com/ubuntu gutsy-security main restricted universe
deb-src http://security.ubuntu.com/ubuntu gutsy-security main restricted universe

#deb http://us.archive.ubuntu.com/ubuntu edgy main restricted universe
#deb-src http://us.archive.ubuntu.com/ubuntu edgy main restricted universe
#deb http://security.ubuntu.com/ubuntu edgy-security main restricted universe
#deb-src http://security.ubuntu.com/ubuntu edgy-security main restricted universe

# deb http://us.archive.ubuntu.com/ubuntu dapper main restricted universe
# deb http://us.archive.ubuntu.com/ubuntu dapper-security main restricted universe

# deb http://packages.dfreer.org feisty main

Since I've upgraded several times, it's probably not a really clean
install...but I don't expect that's the problem in this case.

Please let me know what other information is needed.

cheers,
grant

-- System Information:
Debian Release: lenny/sid
  APT prefers gutsy-security
  APT policy: (500, 'gutsy-security'), (500, 'gutsy')
Architecture: i386 (i686)

Kernel: Linux 2.6.22-14-generic (SMP w/1 CPU core)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages hal depends on:
ii adduser 3.103ubuntu1 Add and remove users and groups
ii dbus 1.1.1-3ubuntu4 simple interprocess messaging syst
ii hal-info 20070618-1ubuntu3 Hardware Abstraction Layer - fdi f
ii libc6 2.6.1-1ubuntu9 GNU C Library: Shared libraries
ii libdbus-1-3 1.1.1-3ubuntu4 simple interprocess messaging syst
ii libdbus-glib-1-2 0.74-1 simple interprocess messaging syst
ii libexpat1 1.95.8-4ubuntu1 XML parsing C library - runtime li
ii libglib2.0-0 2.14.1-1ubuntu1 The GLib library of C routines
ii libhal-storage1 0.5.9.1-6ubuntu5 Hardware Abstraction Layer - share
ii libhal1 0.5.9.1-6ubuntu5 Hardware Abstraction Layer - share
ii libusb-0.1-4 2:0.1.12-7 userspace USB programming library
ii lsb-base 3.1-23.1ubuntu3 Linux Standard Base 3.1 init scrip
ii pciutils 1:2.2.4-1ubuntu2 Linux PCI Utilities
ii udev 113-0ubuntu16 rule-based device node and kernel
ii usbutils 0.72-8ubuntu1 Linux USB utilities
ii zlib1g 1:1.2.3.3.dfsg-5ubuntu2 compression library - runtime

Versions of packages hal recommends:
ii eject 2.1.5-2ubuntu2 ejects CDs and operates CD-Changer

-- no debconf information

On Sat, Jan 05, 2008 at 02:31:21AM -0000, Grant Grundler wrote:
> If I connect the device while hald is running, I get the follow dmesg
> output. Eveything is good up to "Attached scsi generic sg1 type 0"
> output. "reset" is because hald is doing something and results in the
> deivce going "offline". As noted above, stopping hald allows me to read
> from the device.
...
> root@mb500:/etc/udev/rules.d # ls -l /dev/sdb*
> brw-rw---- 1 root plugdev 8, 16 2008-01-04 17:13 /dev/sdb
> brw-rw---- 1 root plugdev 8, 17 2008-01-04 17:13 /dev/sdb1
>
> and I conclude udev is working correctly.

Sorry - this is wrong. Somehow I messed up when trying to triag this bug.
udev by itself (without hald) causes the "device offline" issues.
I tried to reproduce this with udev running and discovered it was
happening anyway. So I can't explain how I reached the conclusion
that it was hald. Perhaps there are other problems with hald as well
that caused the same sometimes or interactions with udev or the
same kernel code invoked by udev.

Issues with booting newer kernels on my laptop have made it difficult
to track down exactly which command sent to the device is causing problems.
Once I track that down, we can decide if this bug should be re-assigned
to udev package or whatever is appropriate. It will probably take another
week since I very little time outside of work to track this down.

again, my apologies for the (likely) misdiagnosis,
grant

Grant Grundler (grundler) wrote :

usbmon output attached. Need someone to interpret this. Sending email to linux-usb.

description: updated
Grant Grundler (grundler) wrote :

Ok. Problem is brain damaged HW. Device reports 1 sector more than it has and wedges when it's accessed.

Jan 19 18:58:48 localhost kernel: scsi 3:0:0:0: Direct-Access HP PhotoSmart R707 A001 PQ: 0 ANSI: 0
Jan 19 18:58:48 localhost kernel: sd 3:0:0:0: [sda] 60801 512-byte hardware sectors (31 MB)
Jan 19 18:58:48 localhost kernel: sd 3:0:0:0: [sda] Write Protect is off
Jan 19 18:58:48 localhost kernel: sd 3:0:0:0: [sda] 60801 512-byte hardware sectors (31 MB)
Jan 19 18:58:48 localhost kernel: sd 3:0:0:0: [sda] Write Protect is off

root@mb500:~ # strace -o strace-dd-HPr707.out dd if=/dev/sda of=/dev/null
skip=60800 count=1
dd: reading `/dev/sda': Input/output error
0+0 records in
0+0 records out
0 bytes (0 B) copied, 55.7303 seconds, 0.0 kB/s

and relevant bit from strace:
open("/dev/sda", O_RDONLY|O_LARGEFILE) = 0
_llseek(0, 0, [0], SEEK_CUR) = 0
close(1) = 0
open("/dev/null", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 1
rt_sigaction(SIGUSR1, NULL, {SIG_DFL}, 8) = 0
rt_sigaction(SIGINT, NULL, {SIG_DFL}, 8) = 0
rt_sigaction(SIGUSR1, {0x80493a0, [INT USR1], 0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x8049390, [INT USR1], SA_NOMASK|SA_ONESHOT}, NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {70667, 216812381}) = 0
ioctl(0, MGSL_IOCSTXIDLE or MTIOCGET or SNDCTL_MIDI_MPUCMD, 0xbf8e31d0) = -1 EIN
VAL (Invalid argument)
_llseek(0, 31129600, [31129600], SEEK_CUR) = 0
read(0, 0x8059000, 512) = -1 EIO (Input/output error)

Strace I collected before of udev and it's children showed /lib/udev/vol_id doing the same thing.

Grant Grundler (grundler) wrote :

Submitted the attached patch to linux-usb mailing list.
Basically black list this device since I've demonstrated it's reporting one sector more than it actually has available and then wedges when reading that last, non-existant sector.

description: updated

Hi Grant,

Sorry for the delayed response. Thanks so much for all the hard work debugging. The patch you attached has already been pulled in to the Hardy kernel. I'll including the Ubuntu Hardy git kernel commit id below for your reference. I'll go ahead and mark this bug as resolved. Thanks again and please continue to report any future bugs that you may find. Thanks!

commit 58f52ce3847d132be9760e7107ad18b6f81d7c0e
Author: Grant Grundler <email address hidden>
Date: Fri Feb 1 15:16:58 2008 -0800

    USB: storage: Add unusual_dev for HP r707

    Add "FIX_CAPACITY" entry for HP Photosmart r707 Camera in "Disk" mode.
    Camera will wedge when /lib/udev/vol_id attempts to access the last sector,
    EIO gets reported to dmesg, and block device is marked "offline" (it is).
    Reproduced vol_id behavior with:
        "dd if=/dev/sda of=/dev/null skip=60800 count=1"

    Signed-off-by: Grant Grundler <email address hidden>
    Signed-off-by: Phil Dibowitz <email address hidden>
    Signed-off-by: Greg Kroah-Hartman <email address hidden>
    Signed-off-by: Amit Kucheria <email address hidden>

Changed in hal:
status: New → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers