Ubuntu

udisks-daemon assertion error: HACK: Wanting to register object at path `%s' but there is already an object there.

Reported by George Shuklin on 2011-12-03
530
This bug affects 67 people
Affects Status Importance Assigned to Milestone
udisks
Fix Released
High
udisks (Ubuntu)
Medium
Martin Pitt

Bug Description

crash after startup

ProblemType: Crash
DistroRelease: Ubuntu 12.04
Package: udisks 1.0.4-2
Uname: Linux 3.2.0-rc3-next-20111202 i686
ApportVersion: 1.90-0ubuntu1
Architecture: i386
Date: Sun Dec 4 02:50:11 2011
ExecutablePath: /usr/lib/udisks/udisks-daemon
Lsusb:
 Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
 Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
 Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
 Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
 Bus 001 Device 003: ID 0421:0518 Nokia Mobile Phones
MachineType: LENOVO 4290RB3
ProcCmdline: /usr/lib/udisks/udisks-daemon
ProcEnviron:

ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.2.0-rc3-next-20111202 root=UUID=ff771e68-857e-4d94-8f9a-90822e3deab4 ro quiet splash i915_enable_rc6 i195.i915_enable_rc6=1 pcie.aspm=force vt.handoff=7
Signal: 5
SourcePackage: udisks
StacktraceTop:
 ?? ()
 ?? ()
 g_udev_marshal_VOID__STRING_OBJECT () from /usr/lib/i386-linux-gnu/libgudev-1.0.so.0
 g_closure_invoke () from /usr/lib/i386-linux-gnu/libgobject-2.0.so.0
 ?? () from /usr/lib/i386-linux-gnu/libgobject-2.0.so.0
Title: udisks-daemon crashed with signal 5 in g_udev_marshal_VOID__STRING_OBJECT()
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups:

dmi.bios.date: 07/01/2011
dmi.bios.vendor: LENOVO
dmi.bios.version: 8DET49WW (1.19 )
dmi.board.asset.tag: Not Available
dmi.board.name: 4290RB3
dmi.board.vendor: LENOVO
dmi.board.version: Not Available
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: Not Available
dmi.modalias: dmi:bvnLENOVO:bvr8DET49WW(1.19):bd07/01/2011:svnLENOVO:pn4290RB3:pvrThinkPadX220:rvnLENOVO:rn4290RB3:rvrNotAvailable:cvnLENOVO:ct10:cvrNotAvailable:
dmi.product.name: 4290RB3
dmi.product.version: ThinkPad X220
dmi.sys.vendor: LENOVO

Related branches

George Shuklin (george-shuklin) wrote :

StacktraceTop:
 register_disks_device (device=0x9504ff0) at device.c:1968
 device_new (daemon=0x94e4c10, d=0x94fa590) at device.c:5159
 block_device_add (emit_event=1, d=0x94fa590, daemon=0x94e4c10) at daemon.c:1340
 device_add (daemon=0x94e4c10, d=0x94fa590, emit_event=1) at daemon.c:1389
 g_udev_marshal_VOID__STRING_OBJECT () from /tmp/tmptNU4ZC/usr/lib/i386-linux-gnu/libgudev-1.0.so.0

Changed in udisks (Ubuntu):
importance: Undecided → Medium
tags: removed: need-i386-retrace

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

Changed in udisks (Ubuntu):
status: New → Confirmed
visibility: private → public
Changed in udisks (Ubuntu):
assignee: nobody → Martin Pitt (pitti)
Martin Pitt (pitti) on 2012-03-21
summary: - udisks-daemon crashed with signal 5 in
- g_udev_marshal_VOID__STRING_OBJECT()
+ udisks-daemon assertion error: HACK: Wanting to register object at path
+ `%s' but there is already an object there.
tags: added: bugpattern-needed
Martin Pitt (pitti) wrote :

Thanks for your reports! I'm afraid I have too little information yet to see what's wrong with this. Is anybody able to reproduce this using a series of steps, possibly with inserting/removing/suspending etc. several times in a row? If you can, please open a terminal and run this:

  sudo /usr/lib/udisks/udisks-daemon --replace 2>&1 | tee /tmp/udisks.log

Then play around with your system until you get a crash, i. e. it prints something like "HACK: Wanting to register object at path..." and returns to the bash prompt. Then please attach /tmp/udisks.log here.

Thanks!

Changed in udisks (Ubuntu):
status: Confirmed → Incomplete
Sebastien Bacher (seb128) wrote :

got the same error while connecting,disconnecting an ipod nano

Sebastien Bacher (seb128) wrote :
Martin Pitt (pitti) wrote :

Sebastien kindly did some more debugging, keeping notes here. This seems to be related to media polling (we verified both in-kernel and udisks based polling trigger this, and cause the same uevents).

Correlating udev events and the corresponding udev debug output, we get:

UDEV [26112.066235] remove /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb/sdb1 (block)
--
**** REMOVING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/
sdb/sdb1
**** EMITTING REMOVED for /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb/sdb1

UDEV [26112.067123] remove /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/sdb (block)
--
**** REMOVING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/
sdb
**** EMITTING REMOVED for /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb
**** scsi_host IGNORING REMOVE /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/scsi_host/h
ost29

Now we get a rather weird change uevent with a hilariously broken device path and device name, at a time when sdb is already gone!

UDEV [26112.087644] change /sdb (block)
ACTION=change
DEVNAME=/dev/sdb
DEVPATH=/sdb
DEVTYPE=disk
DISK_MEDIA_CHANGE=1
SUBSYSTEM=block
--
**** TREATING CHANGE AS ADD /sys/sdb
**** ADDING /sys/sdb
**** UPDATING /sys/sdb
**** ADDED /sys/sdb
**** EMITTING ADDED for /sys/sdb

Now we get a similar change event again, but this time WITHOUT DISK_MEDIA_CHANGE

UDEV [26112.102230] change /sdb (block)
ACTION=change
DEVNAME=/dev/sdb
DEVPATH=/sdb
DEVTYPE=disk
SUBSYSTEM=block
--
**** CHANGING /sys/sdb
**** UPDATING /sys/sdb
**** EMITTING CHANGED for /sys/sdb
**** CHANGED /sys/sdb

Now we get the device back:

UDEV [26123.419938] add /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host32/target32:0:0/32:0:0:0/block/sdb (block)
--
**** ADDING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host32/target32:0:0/32:0:0:0/block/sdb
**** UPDATING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host32/target32:0:0/32:0:0:0/block/sdb

(udisks-daemon:24900): udisks-daemon-ERROR **: **** HACK: Wanting to register object at path `/org/freedesktop/UDisks/devices/sdb' but there is already an object there. This is an internal error in the daemon. Aborting.

So I think the problem is that the media polling for the /sdb device creates a device in udisks.

Changed in udisks (Ubuntu):
status: Incomplete → In Progress
Martin Pitt (pitti) wrote :

For posterity I attach the udisks and udev logs.

Martin Pitt (pitti) wrote :
Martin Pitt (pitti) wrote :

With a little extra debugging, Sebastien's latest log confirms this:

**** TREATING CHANGE AS ADD /sys/sdb
**** ADDING /sys/sdb
**** UPDATING /sys/sdb
**** registering /org/freedesktop/UDisks/devices/sdb

Martin Pitt (pitti) wrote :

This patch should fix it, but as I'm still unable to reproduce I cannot verify this. It could be that the kernel actually has a /sys/sdb when this weird change event happens. Sebastien, can you please apply this and check if it fixes the problem? You should see something like

   Ignoring device with nonexisting native path: /sys/sdb

now, and udisks should just go on.

Also, can you please check if this affects udisks2 in the ubuntu-desktop PPA?

Download full text (4.2 KiB)

In https://bugs.launchpad.net/bugs/899757 we get quite a few duplicates on a crash that looks like this:

#1 0xb74640b3 in g_log (log_domain=0x8072adb "udisks-daemon", log_level=G_LOG_LEVEL_ERROR, format=0x8078cac "**** HACK: Wanting to register object at path `%s' but there is already an object there. This is an internal error in the daemon. Aborting.\n") at /build/buildd/glib2.0-2.30.1/./glib/gmessages.c:591
        args = 0xbfe867ac "`hP\t"
#2 0x08068736 in register_disks_device (device=0x9504ff0) at device.c:1968
        error = 0x0
#3 device_new (daemon=0x94e4c10, d=0x94fa590) at device.c:5159
        device = 0x9504ff0
        native_path = <optimized out>
#4 0x080523d0 in block_device_add (emit_event=1, d=0x94fa590, daemon=0x94e4c10) at daemon.c:1340
        device = <optimized out>
        native_path = 0x94e2ef8 "/sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host7/target7:0:0/7:0:0:0/block/sdb"

(Full trace at https://launchpadlibrarian.net/86784583/Stacktrace.txt, but this is the essential part).

This happens when adding a new device, particular with devices which bounce a bit (i. e. you get several adds, removes, and changes before it stabilizes).

Unfortunately I cannot reproduce this myself with the devices I have, but a colleague of mine (Sebastien Bacher) can reproduce it very easily with his iPod.

After a few rounds of debugging I now understand what happens:

This seems to be related to media polling (we verified both in-kernel and udisks based polling trigger this, and cause the same uevents).

Correlating udev events and the corresponding udev debug output, we get:

UDEV [26112.066235] remove /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb/sdb1 (block)
--
**** REMOVING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/
sdb/sdb1
**** EMITTING REMOVED for /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb/sdb1

UDEV [26112.067123] remove /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/sdb (block)
--
**** REMOVING /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:0:0:0/block/
sdb
**** EMITTING REMOVED for /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/target29:0:0/29:
0:0:0/block/sdb
**** scsi_host IGNORING REMOVE /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4/2-1.4:1.0/host29/scsi_host/h
ost29

Now we get a rather weird change uevent with a hilariously broken device path and device name, at a time when sdb is already gone!

UDEV [26112.087644] change /sdb (block)
ACTION=change
DEVNAME=/dev/sdb
DEVPATH=/sdb
DEVTYPE=disk
DISK_MEDIA_CHANGE=1
SUBSYSTEM=block
--
**** TREATING CHANGE AS ADD /sys/sdb
**** ADDING /sys/sdb
**** UPDATING /sys/sdb
**** ADDED /sys/sdb
**** EMITTING ADDED for /sys/sdb

Now we get a similar change event again, but this time WITHOUT DISK_MEDIA_CHANGE

UDEV [26112.102230] change /sdb (block)
ACTION=change
DEVNAME=/dev/sdb
DEVPATH=/sdb
DEVTYPE=disk
SUBSYSTEM=block
--
**** CHANGING /sys/sdb
**** UPDATING /sys/sdb
**** EMITTING CHANGED for...

Read more...

I'll have Sebastien test a potential patch, I'll submit it here if that is successful. I also asked him to test with udisks2, so that it doesn't get the same problem all over again.

I am not sure whether this is to be considered a kernel bug (sending media change uevents after a device is removed, especially with bogus device paths), but they might be useful for other purposes or hard to avoid.

Within udisks, I see two options to fix this:

 * Drop the "treating change as add" logic. In all my experiments and log files I created for this bug I never saw a situation where a device got added without an "add" event, even with the worst bouncing. I. e. we could just simply ignore change events on nonexisting devices. My gut feeling is that this is the "more" correct approach, and certainly the one we should pursue in udisks2 (if it is affected in the first place).

 * Add a plausibility check to add/change events, to ensure that the native path actually exists before we create an object for it. That's what I'm currently testing. It's much less intrusive and much safer than the first option, so it's appropriate for the udisks1 branch.

Changed in udisks:
importance: Unknown → High
status: Unknown → In Progress
Martin Pitt (pitti) wrote :

Previous patch had a segfault due to a copy&paste error, this patch has been tested by Sebastien. udisks2 is unaffected.

Created attachment 59366
Ignore add/change events for a nonexisting native path

This patch has been verified to work. We also asserted that udisks2 is not affected by this problem (it does not have all these hacks that piled up in udisks to work around past kernel bugs.)

Changed in udisks (Ubuntu):
status: In Progress → Fix Committed
milestone: none → ubuntu-12.04
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package udisks - 1.0.4-5ubuntu1

---------------
udisks (1.0.4-5ubuntu1) precise; urgency=low

  * Merge with Debian unstable. Remaining Ubuntu changes:
    - debian/control: Change the "cryptsetup" suggests to a "cryptsetup-bin"
      recommends, so that LUKS functionality works by default. This change
      needs to be kept in Ubuntu until the cryptsetup package split goes into
      Debian as well. (LP: #343363)

udisks (1.0.4-5) unstable; urgency=low

  * debian/control: Drop ntfsprogs recommendation, it's now a transitional
    package. ntfs-3g provides the programs now.
  * Add debian/patches/00git_media_card_device_tags.patch: Mark MemStick and
    MMC devices as such, so that they get automounted. Backported from
    udisks2. (LP: #942777)
  * Add 12-bogus-uevent-paths.patch: Ignore add/change events for a
    nonexisting native path. (LP: #899757)
  * debian/copyright: Update to copyright 1.0 format.
  * debian/control: Bump Standards-Version to 3.9.3.

udisks (1.0.4-4) unstable; urgency=low

  * Install systemd service file for udisks-daemon.
 -- Martin Pitt <email address hidden> Mon, 02 Apr 2012 12:21:43 +0200

Changed in udisks (Ubuntu):
status: Fix Committed → Fix Released
Download full text (3.3 KiB)

I had this bug by looking after updates with the "update gestion" in ubuntu i386 32b on portable pc hp 2220 sf. 4gb ram, ATI radeon 4500 (video)
All items selected in "update gestion".

A+

Guy Roche

mail <email address hidden>
mail <email address hidden>

domicile 0324 376446
mobile 0619 178018

> Message du 04/04/12 16:26
> de : "MartinPitt"<email address hidden>
> à : <email address hidden>
> cc :
> objet : [Bug 899757]
>
> Created attachment 59366
> Ignore add/change events for a nonexisting native path
>
> This patch has been verified to work. We also asserted that udisks2 is
> not affected by this problem (it does not have all these hacks that
> piled up in udisks to work around past kernel bugs.)
>
> --
> You received this bug notification because you are subscribed to a
> duplicate bug report (963561).
> https://bugs.launchpad.net/bugs/899757
>
> Title:
> udisks-daemon assertion error: HACK: Wanting to register object at
> path `%s' but there is already an object there.
>
> Status in abstraction for enumerating and managing block devices:
> In Progress
> Status in “udisks” package in Ubuntu:
> Fix Released
>
> Bug description:
> crash after startup
>
> ProblemType: Crash
> DistroRelease: Ubuntu 12.04
> Package: udisks 1.0.4-2
> Uname: Linux 3.2.0-rc3-next-20111202 i686
> ApportVersion: 1.90-0ubuntu1
> Architecture: i386
> Date: Sun Dec 4 02:50:11 2011
> ExecutablePath: /usr/lib/udisks/udisks-daemon
> Lsusb:
> Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
> Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
> Bus 001 Device 003: ID 0421:0518 Nokia Mobile Phones
> MachineType: LENOVO 4290RB3
> ProcCmdline: /usr/lib/udisks/udisks-daemon
> ProcEnviron:
>
> ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.2.0-rc3-next-20111202 root=UUID=ff771e68-857e-4d94-8f9a-90822e3deab4 ro quiet splash i915_enable_rc6 i195.i915_enable_rc6=1 pcie.aspm=force vt.handoff=7
> Signal: 5
> SourcePackage: udisks
> StacktraceTop:
> ?? ()
> ?? ()
> g_udev_marshal_VOID__STRING_OBJECT () from /usr/lib/i386-linux-gnu/libgudev-1.0.so.0
> g_closure_invoke () from /usr/lib/i386-linux-gnu/libgobject-2.0.so.0
> ?? () from /usr/lib/i386-linux-gnu/libgobject-2.0.so.0
> Title: udisks-daemon crashed with signal 5 in g_udev_marshal_VOID__STRING_OBJECT()
> UpgradeStatus: No upgrade log present (probably fresh install)
> UserGroups:
>
> dmi.bios.date: 07/01/2011
> dmi.bios.vendor: LENOVO
> dmi.bios.version: 8DET49WW (1.19 )
> dmi.board.asset.tag: Not Available
> dmi.board.name: 4290RB3
> dmi.board.vendor: LENOVO
> dmi.board.version: Not Available
> dmi.chassis.asset.tag: No Asset Information
> dmi.chassis.type: 10
> dmi.chassis.vendor: LENOVO
> dmi.chassis.version: Not Available
> dmi.modalias: dmi:bvnLENOVO:bvr8DET49WW(1.19):bd07/01/2011:svnLENOVO:pn4290RB3:pvrThinkPadX220:rvnLENOVO:rn4290RB3:rvrNotAvailable:cvnLENOVO:ct10:cvrNotAvailable:
> dmi.produ...

Read more...

I pushed this now. It's confirmed to work, and that downstream bug got a gazillion duplicates, so it does hurt people a lot.

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

Other bug subscribers

Remote bug watches

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