gvfs-gphoto2-volume-monitor prevents Sansa e250 player from auto-mounting

[noble]

Binary package hint: gvfs

When I plug in my Sansa e250 audio device it does not auto-mount. After unplugging and plugging it in multiple times I got a crash report from gvfs-gphoto2-volume-monitor, after which the auto-mount worked. I haven't been able to reproduce this crash since. Now I am consistently able to get the device to auto-mount by doing "killall gvfs-gphoto2-volume-monitor" before plugging it in, but nothing at all happens when I plug it in with gvfs-gphoto2-volume-monitor running.

Auto mount was working in Hardy, was not working in Intrepid, and now is not working in Jaunty.

What I expected to happen: Sansa player auto-mounts as USB mass storage device when plugged in.
What happened instead: Nothing happened when I plugged in the audio player.

ProblemType: Bug
Architecture: i386
DistroRelease: Ubuntu 9.04
Package: gvfs-backends 1.2.2-0ubuntu1
ProcEnviron:
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: gvfs
Uname: Linux 2.6.28-11-generic i686

[Sebastien Bacher (seb128)]

thank you for your bug report, so the device is not mounted in nautilus and GNOME? can you run gvfs-mount -li after plugging the device?

[noble (noblebaker)]

Thanks. No, the device is not mounted anywhere that I can see. Here's the output of the command you asked for with gvfs-gphoto2-volume-monitor running and the device plugged in:

$ gvfs-mount -li
Drive(0): CD-RW/DVD±RW Drive
  Type: GProxyDrive (GProxyVolumeMonitorHal)
  ids:
   hal-udi: '/org/freedesktop/Hal/devices/storage_model_DVDRAM_GSA_4083N'
   unix-device: '/dev/sr0'
  themed icons: [drive-optical-recorder] [drive-optical] [drive]
  is_media_removable=1
  has_media=0
  is_media_check_automatic=1
  can_poll_for_media=1
  can_eject=1
Drive(1): Mass Storage Drive
  Type: GProxyDrive (GProxyVolumeMonitorHal)
  ids:
   hal-udi: '/org/freedesktop/Hal/devices/storage_serial_SATA_WDC_WD3200BEVT__WD_WXE208131955'
   unix-device: '/dev/sda'
  themed icons: [drive-removable-media] [drive-removable] [drive]
  is_media_removable=0
  has_media=1
  is_media_check_automatic=0
  can_poll_for_media=0
  can_eject=0
  Volume(0): t60
    Type: GProxyVolume (GProxyVolumeMonitorHal)
    ids:
     uuid: '20f098eb-cb32-42a4-96bb-b2f6be21f28e'
     hal-udi: '/org/freedesktop/Hal/devices/volume_uuid_20f098eb_cb32_42a4_96bb_b2f6be21f28e'
     unix-device: '/dev/sda1'
     label: 't60'
    uuid=20f098eb-cb32-42a4-96bb-b2f6be21f28e
    themed icons: [drive-removable-media] [drive-removable] [drive]
    can_mount=1
    can_eject=0
    Mount(0): t60 -> file:///media/t60
      Type: GProxyMount (GProxyVolumeMonitorHal)
      uuid=20f098eb-cb32-42a4-96bb-b2f6be21f28e
      themed icons: [drive-harddisk] [drive]
      can_unmount=1
      can_eject=0
      is_shadowed=0

[Sebastien Bacher (seb128)]

what sort of device is the one you try to use? the bug should probably be sent to the people writting gvfs on bugzilla.gnome.org by somebody having access to that

[noble (noblebaker)]

The device is a Sansa mp3 player with Rockbox installed.

[John Morris (john-kirsta)]

(Jaunty, i386, desktop)

I see this bug also with a Sansa e260 MP3 player (original firmware - not rockboxed), and have worked around it with the same "kill".

Here's dmesg for it failing:

[ 4501.912018] usb 2-1: new high speed USB device using ehci_hcd and address 9
[ 4502.046938] usb 2-1: configuration #1 chosen from 1 choice
[ 4502.048369] scsi11 : SCSI emulation for USB Mass Storage devices
[ 4502.048541] usb-storage: device found at 9
[ 4502.048543] usb-storage: waiting for device to settle before scanning
[ 4503.312115] usb 2-1: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 192 rq 1 len 1000 ret -110
[ 4504.312099] usb 2-1: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 128 rq 6 len 1000 ret -110
[ 4504.330848] usb 2-1: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 128 rq 6 len 1000 ret -71

Here's dmesg for it working (after killing gvfs-gphoto2-volume-monitor):

[ 4713.988012] usb 2-3: new high speed USB device using ehci_hcd and address 11
[ 4714.959792] usb 2-3: configuration #128 chosen from 1 choice
[ 4714.977091] scsi13 : SCSI emulation for USB Mass Storage devices
[ 4714.977260] usb-storage: device found at 11
[ 4714.977262] usb-storage: waiting for device to settle before scanning
[ 4719.976459] usb-storage: device scan complete
[ 4719.977572] scsi 13:0:0:0: Direct-Access SanDisk Sansa e260 PQ: 0 ANSI: 0
[ 4719.978564] scsi 13:0:0:1: Direct-Access SanDisk Sansa e260 PQ: 0 ANSI: 0
[ 4719.980305] sd 13:0:0:0: [sde] 7854080 512-byte hardware sectors: (4.02 GB/3.74 GiB)
[ 4719.985180] sd 13:0:0:0: [sde] Write Protect is off
[ 4719.985183] sd 13:0:0:0: [sde] Mode Sense: 45 00 00 00
[ 4719.985185] sd 13:0:0:0: [sde] Assuming drive cache: write through
[ 4719.987816] sd 13:0:0:0: [sde] 7854080 512-byte hardware sectors: (4.02 GB/3.74 GiB)
[ 4719.988678] sd 13:0:0:0: [sde] Write Protect is off
[ 4719.988680] sd 13:0:0:0: [sde] Mode Sense: 45 00 00 00
[ 4719.988682] sd 13:0:0:0: [sde] Assuming drive cache: write through
[ 4719.988685] sde: sde1 sde2
[ 4719.999235] sd 13:0:0:0: [sde] Attached SCSI removable disk
[ 4719.999298] sd 13:0:0:0: Attached scsi generic sg5 type 0
[ 4720.000922] sd 13:0:0:1: [sdf] Attached SCSI removable disk
[ 4720.000974] sd 13:0:0:1: Attached scsi generic sg6 type 0

After this I can access the device no problem.

[John Morris (john-kirsta)]

Forgot to say: I also did a chmod -x on the gvfs-gphoto2-volume-monitor executable to stop it launching again.

[John Morris (john-kirsta)]

Looks like this may be an incarnation of bug 330383.

[John Morris (john-kirsta)]

Possibly also the same: bug 350739

[Sebastien Bacher (seb128)]

The issue is an upstream one and it would be nice if somebody having it could send the bug the to the people writting the software (https://wiki.ubuntu.com/Bugs/Upstream/GNOME)

[noble (noblebaker)]

I submitted the bug: http://bugzilla.gnome.org/show_bug.cgi?id=586778

[Pedro Villavicencio (pedro)]

Thanks for sent it upstream.

[noble (noblebaker)]

This seems to be fixed in Karmic.

[Brownout (brownout)]

I still have this problem in Karmic, killing gvfs-gphoto2-volume-monitor allows me to properly sync the device.

[Brandon Thomson (gravix)]

not fixed in Karmic

[David Tombs (dgtombs)]

I'm marking this as fixed since reporter said it was. (There were significant changes to the gphoto2 volume monitor in karmic.)

If anyone still has an issue, please open a new bug with "ubuntu-bug gvfs". Thanks!

[Imran Chaudhry (ichaudhry)]

The reporter said "this seems to be fixed", to me that does not seem 100% sure.

The bug is still present in Karmic. Killing gvfs-gphoto2-volume-monitor does not help.

After killing gvfs-gphoto2-volume-monitor, it almost gets there:

[ 5379.004052] usb 1-1: new high speed USB device using ehci_hcd and address 5
[ 5379.141025] usb 1-1: configuration #1 chosen from 1 choice
[ 5379.162235] scsi5 : SCSI emulation for USB Mass Storage devices
[ 5379.162444] usb-storage: device found at 5
[ 5379.162447] usb-storage: waiting for device to settle before scanning

Without killing it, this is what I get a dmesg output with "usbfs: USBDEVFS_CONTROL failed"

I'm using a Sony B135 MP3 player:
Bus 001 Device 005: ID 054c:036e Sony Corp.

Sorry I didn't open a new bug as stated. It seemd right to append here.

Ubuntu 10.04 is out in a few days. I intend to upgrade and try again.

[David Tombs (dgtombs)]

Imran, since killing gvfs-gphoto2-volume-monitor does not help, you should open a new bug report with "ubuntu-bug linux", probably. Please link to the other report in a comment here. Thanks.

[Holger Mauermann (mauermann)]

This bug is still present in Lucid. My Sandisk Sansa Clip+ MP3 player doesn't mount until gvfs-gphoto2-volume-monitor is killed.

dmesg:

[467318.020039] usb 1-4: new high speed USB device using ehci_hcd and address 28
[467318.181664] usb 1-4: configuration #1 chosen from 1 choice
[467318.184688] scsi23 : SCSI emulation for USB Mass Storage devices
[467318.184859] usb-storage: device found at 28
[467318.184861] usb-storage: waiting for device to settle before scanning
[467319.500152] usb 1-7: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 128 rq 6 len 1000 ret -110
[467323.181403] usb-storage: device scan complete
[467344.160057] usb 1-4: reset high speed USB device using ehci_hcd and address 28
[467345.271304] usb 1-4: reset high speed USB device using ehci_hcd and address 28
[467351.920035] usb 1-4: reset high speed USB device using ehci_hcd and address 28
[467352.540058] usb 1-4: reset high speed USB device using ehci_hcd and address 28
[467353.530043] usb 1-4: reset high speed USB device using ehci_hcd and address 28
[467353.996444] scsi 23:0:0:0: Device offlined - not ready after error recovery

dmesg after killing gvfs-gphoto2-volume-monitor and successful mount:

[467570.090040] usb 1-4: new high speed USB device using ehci_hcd and address 30
[467570.241607] usb 1-4: configuration #1 chosen from 1 choice
[467570.243744] scsi24 : SCSI emulation for USB Mass Storage devices
[467570.243943] usb-storage: device found at 30
[467570.243945] usb-storage: waiting for device to settle before scanning
[467575.240344] usb-storage: device scan complete
[467575.240942] scsi 24:0:0:0: Direct-Access SanDisk Sansa Clip+ 2GB v01. PQ: 0 ANSI: 0
[467575.241564] scsi 24:0:0:1: Direct-Access SanDisk Sansa Clip+ 2GB v01. PQ: 0 ANSI: 0
[467575.242189] sd 24:0:0:0: Attached scsi generic sg5 type 0
[467575.242914] sd 24:0:0:1: Attached scsi generic sg6 type 0
[467575.249940] sd 24:0:0:0: [sde] 3801088 512-byte logical blocks: (1.94 GB/1.81 GiB)
[467575.251676] sd 24:0:0:0: [sde] Write Protect is off
[467575.251681] sd 24:0:0:0: [sde] Mode Sense: 04 00 00 00
[467575.251684] sd 24:0:0:0: [sde] Assuming drive cache: write through
[467575.252715] sd 24:0:0:1: [sdf] Attached SCSI removable disk
[467575.253710] sd 24:0:0:0: [sde] Assuming drive cache: write through
[467575.253716] sde:
[467575.259417] sd 24:0:0:0: [sde] Assuming drive cache: write through
[467575.259424] sd 24:0:0:0: [sde] Attached SCSI removable disk

[Ingo Ruhnke (grumbel)]

Bug is still present in 10.10 Maverik:

Plugging a Sansa Clip+ MP3 player into USB gives the following dmesg output:

$ dmesg
[34194.116309] hub 2-0:1.0: unable to enumerate USB device on port 4
[34195.884039] usb 2-4: new high speed USB device using ehci_hcd and address 8
[34196.023380] scsi11 : usb-storage 2-4:1.0
[34197.020929] scsi 11:0:0:0: Direct-Access SanDisk Sansa Clip+ 4GB v01. PQ: 0 ANSI: 0
[34197.021412] scsi 11:0:0:1: Direct-Access SanDisk Sansa Clip+ 4GB v01. PQ: 0 ANSI: 0
[34197.022056] sd 11:0:0:0: Attached scsi generic sg6 type 0
[34197.022274] sd 11:0:0:1: Attached scsi generic sg7 type 0
[34197.024413] sd 11:0:0:0: [sdf] 7683072 512-byte logical blocks: (3.93 GB/3.66 GiB)
[34197.027268] sd 11:0:0:1: [sdg] Attached SCSI removable disk
[34197.028738] sd 11:0:0:0: [sdf] Write Protect is off
[34197.028744] sd 11:0:0:0: [sdf] Mode Sense: 04 00 00 00
[34197.028748] sd 11:0:0:0: [sdf] Assuming drive cache: write through
[34197.031557] sd 11:0:0:0: [sdf] Assuming drive cache: write through
[34197.031566] sdf:
[34197.037913] sd 11:0:0:0: [sdf] Assuming drive cache: write through
[34197.037919] sd 11:0:0:0: [sdf] Attached SCSI removable disk
[34197.237720] usb 3-2: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 128 rq 6 len 1000 ret -110
[34198.409977] usb 3-2: usbfs: USBDEVFS_CONTROL failed cmd gvfs-gphoto2-vo rqt 128 rq 6 len 1000 ret -110

If one tries to mount it:

$ sudo mount /dev/sdf /mnt
mount: /dev/sdf is not a valid block device

$ dmesg
[34228.176043] usb 2-4: reset high speed USB device using ehci_hcd and address 8
[34238.692524] usb 2-4: reset high speed USB device using ehci_hcd and address 8
[34255.200532] usb 2-4: reset high speed USB device using ehci_hcd and address 8
[34255.736606] usb 2-4: reset high speed USB device using ehci_hcd and address 8
[34266.364106] usb 2-4: reset high speed USB device using ehci_hcd and address 8
[34266.800557] sd 11:0:0:0: Device offlined - not ready after error recovery
[34266.800570] sd 11:0:0:0: [sdf] Unhandled error code
[34266.800573] sd 11:0:0:0: [sdf] Result: hostbyte=DID_ABORT driverbyte=DRIVER_OK
[34266.800578] sd 11:0:0:0: [sdf] CDB: Read(10): 28 00 00 44 0d 38 00 00 40 00
[34266.800590] end_request: I/O error, dev sdf, sector 4459832
[34266.800596] Buffer I/O error on device sdf, logical block 557479
[34266.800604] Buffer I/O error on device sdf, logical block 557480
[34266.800608] Buffer I/O error on device sdf, logical block 557481
[34266.800612] Buffer I/O error on device sdf, logical block 557482
[34266.800616] Buffer I/O error on device sdf, logical block 557483
[34266.800619] Buffer I/O error on device sdf, logical block 557484
[34266.800623] Buffer I/O error on device sdf, logical block 557485
[34266.800627] Buffer I/O error on device sdf, logical block 557486
[34266.800631] sd 11:0:0:0: rejecting I/O to offline device
[34266.800747] sd 11:0:0:0: rejecting I/O to offline device
[34266.800824] sd 11:0:0:0: rejecting I/O to offline device
[34266.800845] sd 11:0:0:0: rejecting I/O to offline device
[34266.800937] sd 11:0:0:0: rejecting I/O to offline device
[34266.801001] sd 11:0:0:0: rejecting I/O to offline device
[34266.801065] sd 11:0:0:0: reje...

[Ingo Ruhnke (grumbel)]

Bug is still present in Ubuntu 11.10 oneiric, killing gvfs-gphoto2-volume-monitor again works as workaround.

[David Tombs (dgtombs)]

Hi Ingo, Please file a new bug report with 'ubuntu-bug storage'. Thanks!

---
Ubuntu Bug Squad volunteer triager
http://wiki.ubuntu.com/BugSquad