Erasing disk failed: Error wiping newly created partition

[Ville Ranki]

I tried to erase a normal 8GB USB stick on up to date Ubuntu 15.04. This dialog appeared:

org.freedesktop.DBus.Python.GLib.Error: Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/share/usb-creator/usb-creator-helper", line 287, in Format
    partition = table.call_create_partition_sync(0, size, '0x0c', '', no_options, None)
GLib.Error: udisks-error-quark: GDBus.Error:org.freedesktop.UDisks2.Error.Failed: Error wiping newly created partition /dev/sdc1: Command-line `wipefs -a "/dev/sdc1"' exited with non-zero exit status 1: wipefs: error: /dev/sdc1: probing initialization failed: No such file or directory
 (0)

ProblemType: Bug
DistroRelease: Ubuntu 15.04
Package: usb-creator-gtk 0.2.67ubuntu0.1
ProcVersionSignature: Ubuntu 3.19.0-18.18-generic 3.19.6
Uname: Linux 3.19.0-18-generic x86_64
NonfreeKernelModules: nvidia
ApportVersion: 2.17.2-0ubuntu1.1
Architecture: amd64
CurrentDesktop: X-Cinnamon
Date: Mon Jun 1 13:20:30 2015
EcryptfsInUse: Yes
InstallationDate: Installed on 2015-02-12 (108 days ago)
InstallationMedia: Ubuntu 14.10 "Utopic Unicorn" - Release amd64 (20141022.1)
SourcePackage: usb-creator
UDisksDump: Error: [Errno 2] No such file or directory: 'udisks'
UpgradeStatus: Upgraded to vivid on 2015-05-12 (19 days ago)

[intrigeri (intrigeri)]

Hi,

I'm using GNOME Disks 3.12.1-1+b1 on current Debian unstable, with udisks2 (2.1.3-5), gvfs (1.22.1-1) and libatasmart4 0.19-3.

Steps to reproduce:

1. Blank a USB drive (dd if=/dev/zero)

2. Format that USB drive with GNOME Disks (default options: quick and MBR)

3. Attempt to create a new partition+filesystem on that USB drive using the "+" icon in GNOME Disks (default options, again: don't overwrite, FAT, no label)

* I always get this error in a dialog:

  Error creating partition
  Error wiping newly created partition /dev/sdb1: Command-line `wipefs -a "/dev/sdb1"' exited with non-zero exit status 1:
  wipefs: error: /dev/sdb1: probing initialization failed: No such file or directory
  (udisks-error-quark, 0)

* The sdb1 partition is always created.

* Sometimes the FAT filesystem is created on this partition, sometimes not.

* In any case, I can then reliably "Format" the newly created partition with GNOME Disks and get a filesystem created as expected.

Seems like udisks is trying to act on a device before the device node appears. The affected code seems to live in src/udiskslinuxpartitiontable.c, that pretends to "sit and wait for the partition to show up" before wiping the newly created partition, but apparently doesn't reliably wait for the device node to appear in /dev.

[intrigeri (intrigeri)]

I retried the same when running udisksd without --no-debug. The journal (for the partition+FS creation) says:

Oct 26 11:29:02 sid-desktop kernel: sda: sda1
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.286:[1790]:[DEBUG]: uevent change /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.287:[1795]:[INFO]: Cleanup check start [udisksstate.c:419, udisks_state_check_in_thread()]
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.287:[1795]:[INFO]: Cleanup check end [udisksstate.c:457, udisks_state_check_in_thread()]
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.771:[1790]:[DEBUG]: uevent add /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda/sda1 [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]
Oct 26 11:29:03 sid-desktop kernel: sda: sda1
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.817:[1790]:[DEBUG]: uevent remove /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda/sda1 [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.817:[1795]:[INFO]: Cleanup check start [udisksstate.c:419, udisks_state_check_in_thread()]
Oct 26 11:29:03 sid-desktop udisksd[1790]: 11:29:03.818:[1795]:[INFO]: Cleanup check end [udisksstate.c:457, udisks_state_check_in_thread()]
Oct 26 11:29:04 sid-desktop udisksd[1790]: 11:29:04.416:[1790]:[DEBUG]: uevent change /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]
Oct 26 11:29:04 sid-desktop udisksd[1790]: 11:29:04.416:[1795]:[INFO]: Cleanup check start [udisksstate.c:419, udisks_state_check_in_thread()]
Oct 26 11:29:04 sid-desktop udisksd[1790]: 11:29:04.416:[1795]:[INFO]: Cleanup check end [udisksstate.c:457, udisks_state_check_in_thread()]
Oct 26 11:29:05 sid-desktop udisksd[1790]: 11:29:05.004:[1790]:[DEBUG]: uevent change /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]
Oct 26 11:29:05 sid-desktop udisksd[1790]: 11:29:05.004:[1795]:[INFO]: Cleanup check start [udisksstate.c:419, udisks_state_check_in_thread()]
Oct 26 11:29:05 sid-desktop udisksd[1790]: 11:29:05.004:[1795]:[INFO]: Cleanup check end [udisksstate.c:457, udisks_state_check_in_thread()]
Oct 26 11:29:05 sid-desktop udisksd[1790]: 11:29:05.482:[1790]:[DEBUG]: uevent add /sys/devices/pci0000:00/0000:00:01.2/usb1/1-2/1-2.2/1-2.2:1.0/host8/target8:0:0/8:0:0:0/block/sda/sda1 [udiskslinuxprovider.c:902, udisks_linux_provider_handle_uevent()]

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[intrigeri (intrigeri)]

Reproduced with udisks 2.1.6-2 on current Debian sid, this time in Python, with any of direct D-Bus calls (both sync and async), libudisks (both sync and async) and gdbus. This tends to confirm that the bug is in UDisks2 itself.

[sudodus (nio-wiklund)]

My tip for a solution is independent of waiting for udisks to be fixed:

* Wipe the first megabyte (actually mibibyte) *

When the target drive is identified and selected (so that there can be no mistake), simply wipe the first mibibyte (use dd under the hood to overwrite it with zeros). This has worked well for me and people I have helped at the Ubuntu Forums. It is part of mkusb and I have used and recommended the method for years. mkusb from ppa:mkusb/unstable has a menu with several alternatives, where the first one (standard) will create pendrives, that work with for example the s-d-c and Unetbootin.

[Marc Deslauriers (mdeslaur)]

I can reproduce this with udisks2 in vivid.

[Ubuntu QA Website (ubuntuqa)]

This bug has been reported on the Ubuntu ISO testing tracker.

A list of all reports related to this bug can be found here:
http://iso.qa.ubuntu.com/qatracker/reports/bugs/1460602

[Marc Deslauriers (mdeslaur)]

Here's my understanding of this issue:

In src/udiskslinuxpartitiontable.c, handle_create_partition():

1- New partition is created by calling parted
2- udisks_linux_block_object_trigger_uevent() is called to trigger udev
3- Wait for partition to show up by using wait_for_partition()
4- Wipe new partition by calling wipefs
5- udisks_linux_block_object_trigger_uevent() is called to trigger udev

The problem arises because #2 and #5 aren't done synchronously. When udev processes the device change request, it removes the newly created partition device (ie: sdb1), and then adds it back again. This happens in a race with #4, and results in wipefs being called while the device is removed.

This issue can be solved in a few ways, from best to worst:

1- Create a sync version of udisks_linux_block_object_trigger_uevent() that waits until the device is actually handled in #2 and #5
2- Make sure there are no pending events in the udev queue after #2 and #5
3- Adding an artificial delay after #2 and #5 to wait until the device has settled down (some places in the code add a udisks_linux_block_object_reread_partition_table(), which I assume results in enough delay to not hit the race most of the time.)

I've tried removing #2 and #5 altogether, and that appeared to work also, but then gnome-disks crashes because udev hasn't added the device back fast enough after the wipefs.

[Martin Pitt (pitti)]

I applied Mathieu's patch: https://cgit.freedesktop.org/udisks/commit/?id=5c859c99dfcd3625

Thank you!

[Martin Pitt (pitti)]

I applied Mathieu's patch upstream, thank you! Landing this is currently blocked on the autopkgtest regressions, I'll look into those (that's a bit convoluted).

[Launchpad Janitor (janitor)]

This bug was fixed in the package udisks2 - 2.1.7-1ubuntu1

---------------
udisks2 (2.1.7-1ubuntu1) xenial; urgency=medium

  * debian/patches/reread_parttable.patch: Reread partition table before
    wiping new partitions we just created. This helps ensure we got the device
    nodes we need from udev (and thus avoids gnome-disks crashing so much, for
    instance, when creating partitions). (LP: #1460602)

 -- Mathieu Trudel-Lapierre <email address hidden> Fri, 01 Apr 2016 15:02:31 -0400

[Martin Pitt (pitti)]

This isn't sufficient. I've still seen this happen in yakkety even. Reopening, in the upstream bug there is a proposal for a better solution which already landed in storaged.

[Martin Pitt (pitti)]

https://cgit.freedesktop.org/udisks/commit/?id=e168e59f
https://cgit.freedesktop.org/udisks/commit/?id=554daa4b

I tried this with an USB stick; I do get the wipefs failure pretty consistently, and with this creating the partition and FS seems to work reliably. I think we ought to SRU this into xenial as well, after giving it some field testing.

[Launchpad Janitor (janitor)]

This bug was fixed in the package udisks2 - 2.1.8-1

---------------
udisks2 (2.1.8-1) unstable; urgency=medium

  * New upstream version:
    - Fixes race condition with creating and formatting partitions.
      (Closes: #767457, LP: #1460602)
  * debian/tests/upstream-system: Drop unnecessary dbus-run-session.
  * debian/tests/upstream-system: Collect core dump when the test crashes.
    This ought to help with tracking down https://launchpad.net/bugs/1585382.
  * Suggest btrfs-progs as preferred alternative to btrfs-tools
    (Closes: #842436)

 -- Martin Pitt <email address hidden> Fri, 25 Nov 2016 11:16:50 +0100

[Amr Ibrahim (amribrahim1987)]

Ping! SRU to Xenial?