GNOME Bugzilla – Bug 746769
bogus "you can now unplug" even though volume is still mounted
Last modified: 2015-12-07 09:40:45 UTC
gnome-shell-3.15.92-2.fc22.x86_64 nautilus-3.15.92-1.fc22.x86_64 This is not a regression. This could result in data loss. 1. Btrfs raid1 volume named "verb" is made from two USB hard drives, is connected ## Nautilus mounts this volume; and it appears in the sidebar twice. 2. Click the "eject" icon to unmount the volume. ## I get two messages: - top notification saying "Writing data to verb - don't unplug until finished" - modal authentication dialog saying it was mounted by another user (which it wasn't, nautilus mounted it in step 1) 3. Click Cancel to the authentication dialog ## top message now says "You can now unplug verb" yet the volume is still mounted! 4. Click the "eject" icon to unmount the drive. 5. Authenticate ## top message now says "You can now unplug verb"; the volume has been unmounted (confirmed with df, mount, and journalctl). Sometimes, usually it's the first attempt, I do not get any messages at all when I click the eject button. This is what journalctl -b -l reports for the whole sequence of plugging in the drive, seeing it mount, clicking on a text file, then clicking the eject button once (no messages at all in Nautilus, and the eject icon to the right of "verb" is still present). Mar 25 12:22:10 f22m.localdomain kernel: usb 1-1.3: new high-speed USB device number 9 using ehci-pci Mar 25 12:22:10 f22m.localdomain kernel: usb 1-1.3: New USB device found, idVendor=050d, idProduct=0237 Mar 25 12:22:10 f22m.localdomain kernel: usb 1-1.3: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Mar 25 12:22:10 f22m.localdomain kernel: hub 1-1.3:1.0: USB hub found Mar 25 12:22:10 f22m.localdomain kernel: hub 1-1.3:1.0: 7 ports detected Mar 25 12:22:10 f22m.localdomain kernel: usb 1-1.3.4: new high-speed USB device number 10 using ehci-pci Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.4: New USB device found, idVendor=174c, idProduct=5136 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.4: New USB device strings: Mfr=2, Product=3, SerialNumber=1 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.4: Product: AS2105 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.4: Manufacturer: ASMedia Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.4: SerialNumber: 00000000000000000000 Mar 25 12:22:11 f22m.localdomain kernel: usb-storage 1-1.3.4:1.0: USB Mass Storage device detected Mar 25 12:22:11 f22m.localdomain kernel: scsi host8: usb-storage 1-1.3.4:1.0 Mar 25 12:22:11 f22m.localdomain mtp-probe[8162]: checking bus 1, device 10: "/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4" Mar 25 12:22:11 f22m.localdomain mtp-probe[8162]: bus: 1, device: 10 was not an MTP device Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: new high-speed USB device number 11 using ehci-pci Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: New USB device found, idVendor=174c, idProduct=5136 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: New USB device strings: Mfr=2, Product=3, SerialNumber=1 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: Product: AS2105 Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: Manufacturer: ASMedia Mar 25 12:22:11 f22m.localdomain kernel: usb 1-1.3.5: SerialNumber: 00000000000000000000 Mar 25 12:22:11 f22m.localdomain kernel: usb-storage 1-1.3.5:1.0: USB Mass Storage device detected Mar 25 12:22:11 f22m.localdomain kernel: scsi host9: usb-storage 1-1.3.5:1.0 Mar 25 12:22:11 f22m.localdomain mtp-probe[8167]: checking bus 1, device 11: "/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5" Mar 25 12:22:11 f22m.localdomain mtp-probe[8167]: bus: 1, device: 11 was not an MTP device Mar 25 12:22:12 f22m.localdomain kernel: scsi 8:0:0:0: Direct-Access ASMT 2105 0 PQ: 0 ANSI: 6 Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: Attached scsi generic sg2 type 0 Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: [sdb] 1465149168 512-byte logical blocks: (750 GB/698 GiB) Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: [sdb] Write Protect is off Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: [sdb] Mode Sense: 43 00 00 00 Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Mar 25 12:22:12 f22m.localdomain kernel: scsi 9:0:0:0: Direct-Access ASMT 2105 0 PQ: 0 ANSI: 6 Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: Attached scsi generic sg3 type 0 Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: [sdc] 1465149168 512-byte logical blocks: (750 GB/698 GiB) Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: [sdc] Write Protect is off Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: [sdc] Mode Sense: 43 00 00 00 Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Mar 25 12:22:12 f22m.localdomain kernel: sd 8:0:0:0: [sdb] Attached SCSI disk Mar 25 12:22:12 f22m.localdomain kernel: sd 9:0:0:0: [sdc] Attached SCSI disk Mar 25 12:22:12 f22m.localdomain kernel: BTRFS info (device sdc): disk space caching is enabled Mar 25 12:22:12 f22m.localdomain kernel: BTRFS: has skinny extents Mar 25 12:22:12 f22m.localdomain systemd[1628]: Device dev-disk-by\x2dlabel-verb.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:12 f22m.localdomain systemd[921]: Device dev-disk-by\x2dlabel-verb.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:12 f22m.localdomain systemd[1]: Device dev-disk-by\x2dlabel-verb.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:12 f22m.localdomain systemd[1628]: Device dev-disk-by\x2duuid-197606b2\x2d9f4a\x2d4742\x2d8824\x2d7fc93285c29c.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:12 f22m.localdomain systemd[921]: Device dev-disk-by\x2duuid-197606b2\x2d9f4a\x2d4742\x2d8824\x2d7fc93285c29c.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:12 f22m.localdomain systemd[1]: Device dev-disk-by\x2duuid-197606b2\x2d9f4a\x2d4742\x2d8824\x2d7fc93285c29c.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/host8/target8:0:0/8:0:0:0/block/sdb and /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-1/1-1.3/1-1.3.5/1-1.3.5:1.0/host9/target9:0:0/9:0:0:0/block/sdc Mar 25 12:22:15 f22m.localdomain udisksd[1429]: Mounted /dev/sdb at /run/media/chris/verb on behalf of uid 1000 Mar 25 12:22:15 f22m.localdomain org.gtk.Private.UDisks2VolumeMonitor[1797]: index_parse.c:190: indx_parse(): error opening /run/media/chris/verb/BDMV/index.bdmv Mar 25 12:22:15 f22m.localdomain org.gtk.Private.UDisks2VolumeMonitor[1797]: index_parse.c:190: indx_parse(): error opening /run/media/chris/verb/BDMV/BACKUP/index.bdmv Mar 25 12:22:15 f22m.localdomain udisksd[1429]: Mounted /dev/sdc at /run/media/chris/verb1 on behalf of uid 1000 Mar 25 12:22:15 f22m.localdomain /usr/libexec/gdm-x-session[1732]: Activating service name='org.gnome.Shell.HotplugSniffer' Mar 25 12:22:15 f22m.localdomain /usr/libexec/gdm-x-session[1732]: Successfully activated service 'org.gnome.Shell.HotplugSniffer' Mar 25 12:22:20 f22m.localdomain unknown[1]: <audit-1131> pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fprintd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Mar 25 12:22:26 f22m.localdomain dbus[753]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' Mar 25 12:22:26 f22m.localdomain systemd[1]: Starting Hostname Service... Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=filter family=2 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=raw family=2 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=security family=2 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=mangle family=2 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=nat family=2 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=filter family=10 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=raw family=10 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=security family=10 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=mangle family=10 entries=0 Mar 25 12:22:26 f22m.localdomain unknown: <audit-1325> table=nat family=10 entries=0 Mar 25 12:22:26 f22m.localdomain dbus[753]: [system] Successfully activated service 'org.freedesktop.hostname1' Mar 25 12:22:26 f22m.localdomain systemd[1]: Started Hostname Service. Mar 25 12:22:26 f22m.localdomain unknown[1]: <audit-1130> pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Mar 25 12:22:31 f22m.localdomain /usr/libexec/gdm-x-session[1732]: Activating service name='org.gnome.gedit' Mar 25 12:22:31 f22m.localdomain /usr/libexec/gdm-x-session[1732]: Successfully activated service 'org.gnome.gedit' Mar 25 12:22:38 f22m.localdomain udisksd[1429]: Cleaning up mount point /run/media/chris/verb (device 8:16 is not mounted) Mar 25 12:22:38 f22m.localdomain udisksd[1429]: Error cleaning up mount point /run/media/chris/verb: Error removing directory: Device or resource busy Mar 25 12:22:38 f22m.localdomain udisksd[1429]: Cleaning up mount point /run/media/chris/verb1 (device 8:32 is not mounted) Mar 25 12:22:38 f22m.localdomain udisksd[1429]: Unmounted /dev/sdc on behalf of uid 1000 Mar 25 12:22:41 f22m.localdomain gnome-session[1805]: (tracker-extract:2238): libmediaart-WARNING **: Unmount operation failed, adding back mount point... Mar 25 12:22:41 f22m.localdomain gnome-session[1805]: (tracker-miner-fs:2241): Tracker-WARNING **: Unmount operation failed, adding back mount point... If I click eject again, I get the authentication required dialog, then click cancel and get a top notification that it's OK to unplug verb. And journal contains this: Mar 25 12:23:17 f22m.localdomain dbus[753]: [system] Activating via systemd: service name='net.reactivated.Fprint' unit='fprintd.service' Mar 25 12:23:17 f22m.localdomain systemd[1]: Starting Fingerprint Authentication Daemon... Mar 25 12:23:17 f22m.localdomain dbus[753]: [system] Successfully activated service 'net.reactivated.Fprint' Mar 25 12:23:17 f22m.localdomain systemd[1]: Started Fingerprint Authentication Daemon. Mar 25 12:23:17 f22m.localdomain unknown[1]: <audit-1130> pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fprintd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Mar 25 12:23:20 f22m.localdomain polkitd[781]: Operator of unix-session:1 FAILED to authenticate to gain authorization for action org.freedesktop.udisks2.filesystem-unmount-others for system-bus-name::1.64 [/usr/libexec/gvfs-udisks2-volume-monitor] (owned by unix-user:chris) Mar 25 12:23:20 f22m.localdomain gnome-session[1805]: (tracker-miner-fs:2241): Tracker-WARNING **: Unmount operation failed, adding back mount point... Mar 25 12:23:20 f22m.localdomain gnome-session[1805]: (tracker-extract:2238): libmediaart-WARNING **: Unmount operation failed, adding back mount point... Mar 25 12:23:47 f22m.localdomain unknown[1]: <audit-1131> pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fprintd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' The volume is still mounted however, so it's not safe to unplug it. Related bug: https://bugs.freedesktop.org/show_bug.cgi?id=87277
Created attachment 300304 [details] journal Entire journal for this boot, using journalctl -b -l -o short-monotonic
Created attachment 300305 [details] sidebar screenshot Shows two "verb" instances.
-> gvfs Not sure what's happening here, but this sounds more like an issue in gvfs or deeper layers.
As with your other btrfs bug against gvfs, I think the issues are that udisks2 doesn't handle complex btrfs setups very well and so it probably needs to be fixed there. Once it is fixed in udisks, it should just expose a single disk to gvfs and everything should work OK.
No, sorry, this is not specific to btrfs and also happens on other volumes. I'm seeing this issue on a Fedora 22 machine with ext on LUKS partition. With one difference: I get both the dialog that it failed and the notification that it succeeded every time I try, not starting with the second try.
You are right! "You can now unplug..." notification is shown regardless of errors. One of the places, where error could happen is code to lock encrypted devices... This is even more visible after fixing Bug 750267...
Created attachment 312734 [details] [review] udisks2: Do not show notification if unmount failed
Review of attachment 312734 [details] [review]: Seems OK on principle, but I think it would be better to add a failed flag to UnmountNotifyData and/or UnmountData rather than passing around an additional boolean everywhere.
Created attachment 316380 [details] [review] udisks2: Do not show notification if unmount failed Thanks for review, ok, I added failed flag in UnmountData. I don't see any advantages of adding the flag in UnmountNotifyData. I have to retest the patch... (Would be best to port the code to GTask and then might be possible to use g_task_had_error instead of the failed flag)
Review of attachment 316380 [details] [review]: Looks good. I assume it works OK?
Comment on attachment 316380 [details] [review] udisks2: Do not show notification if unmount failed Thanks for the review. I made several tests with usb drives and it worked as expected for that cases... Pushed to master (commit 1758ee7), gnome-3-18 (commit c5a3b9c) and gnome-3-16 (commit 6605a07).