Erasing disk failed: Error wiping newly created partition

Bug #1460602 reported by Ville Ranki on 2015-06-01
60
This bug affects 10 people
Affects Status Importance Assigned to Milestone
udisks
Unknown
Unknown
udisks2 (Debian)
Fix Released
Unknown
udisks2 (Ubuntu)
High
Martin Pitt
Xenial
Undecided
Unassigned

Bug Description

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)

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.

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()]

Ville Ranki (ville-ranki) wrote :
Launchpad Janitor (janitor) wrote :

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

Changed in usb-creator (Ubuntu):
status: New → Confirmed
Changed in usb-creator (Ubuntu):
importance: Undecided → High

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) wrote :

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) wrote :

I can reproduce this with udisks2 in vivid.

affects: usb-creator (Ubuntu) → udisks2 (Ubuntu)
Changed in udisks2 (Debian):
status: Unknown → Confirmed
Changed in udisks:
importance: Unknown → Medium
status: Unknown → Confirmed
Ubuntu QA Website (ubuntuqa) wrote :

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

tags: added: iso-testing

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) wrote :

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).

Changed in udisks2 (Ubuntu):
status: Confirmed → Fix Committed
Launchpad Janitor (janitor) wrote :

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

Changed in udisks2 (Ubuntu):
status: Fix Committed → Fix Released
Changed in udisks:
status: Confirmed → Fix Released
Jeremy Bicha (jbicha) on 2016-06-25
Changed in udisks:
importance: Medium → Undecided
status: Fix Released → New
importance: Undecided → Unknown
status: New → Unknown
Martin Pitt (pitti) wrote :

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.

Changed in udisks2 (Ubuntu):
assignee: nobody → Martin Pitt (pitti)
status: Fix Released → In Progress
Martin Pitt (pitti) wrote :

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.

Changed in udisks2 (Ubuntu):
status: In Progress → Fix Committed
Launchpad Janitor (janitor) wrote :

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

Changed in udisks2 (Ubuntu):
status: Fix Committed → Fix Released
Changed in udisks2 (Debian):
status: Confirmed → Fix Released
tags: added: xenial
Amr Ibrahim (amribrahim1987) wrote :

Ping! SRU to Xenial?

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.