dbus proxy delay using udisks with vdev

[gnuinos]

Hi all,

I'm trying to integrate udisks with vdev, a device manager developed by Jude Nelson that works in combination with libudev-compat (as a replacement for libudev). It happens that when I run udiskctl devices are immediately mounted/unmounted; however, I get a delay in the g_dbus_proxy_call because (for some unknown reason) the callback udisks_filesystem_call_mount_finish is invoked in udisks-generated.c once the timeout (~25 sec) has expired.

As explained in the link below:

https://www.gnuinos.org/libudev-compat

libudev-compat removes the netlink connection to udevd in favor of creating and watching a per-process specific directory located in the /dev filesystem directly. I've verified that the libudev clients are receiving the udev_devices as expected.

It's worth to clarify that, if I run the udevadm monitor during the process (although udevd isn't installed, some features of udevadm still work) I get the same result compared to udev/eudev. So, apparently everything is working fine except for the dbus proxy delay.

On the other hand, the aforementioned delay occurs in the case of asynchronous dbus method calls as well. Therefore, I have replaced the use of gvfs_udisks2_volume_mount in gvfs with another tool as a temporary workaround .

You can test this behaviour in the iso images of gnuinos https://www.gnuinos.org/mirror/daedalus, but don't use the volume manager of thunar because, as I already explained above, gvfs in gnuinos doesn't use udisks so far. For testing purposes, use synchorouns method calls via udisksctl instead.

Any hints about how to solve this delay?

Thanks in advance,

Aitor.

[tbzatek]

When you receive the callback, what is the result and error?

Internally UDisks is built on top of libudev. We haven't tested any replacements. Historically it was running fine with eudev as it was essentially just a fork of old udev.

Also, udisks heavily depends on synthetic uevent tagging and that all the extra arguments are properly propagated back through libudev.

[gnuinos]

Thanks for your reply, tbzatek. Yes, internally UDisk is built on top of libgudev, which at the same is built on top of libudev, but the API/ABI compatibility of vdev has been tested with both of them. On the other hand, udisks2 remains running fine with eudev nowadays. But I find Jude Nelson's point of view quite interesting as well.

I was aware of the heavy dependency on synthetic uevent tagging since kernel-4.13 because a couple of days ago I read the following article that explains it in detail: https://storageapis.wordpress.com/2020/04/09/the-road-to-udisks-2-9-0. Indeed, today I've found a function called udisks_daemon_util_trigger_uevent_sync in udisksdaemonutil.c which works asynchronously in case of bd_utils_check_linux_version (4, 13, 0) < 0. And I've also found in this function a callback called uevent_probed_cb requesting the synthetic variable SYNTH_ARG_UDISKSSERIAL, that seems to be missing in vdev. In fact, if I invoke g_main_loop_quit (data->main_loop) in this callback by-passing the request, everything works fine!

Therefore, we have a new device manager working fine with udisks2 from now on, and you can tag this discussion as SOLVED. Thank yo so much!

[tbzatek]

In fact, if I invoke g_main_loop_quit (data->main_loop) in this callback by-passing the request, everything works fine!

In fact, you're breaking needed functionality this way. The synthetic uevent tagging is there for a reason.

If you talk about ABI, it's not just API and its binary form. It's the expected/documented behaviour and order of events for example. This kind of missing functionality should be implemented by vdev.

[gnuinos]

I applied the local change to udisks with the sole purpose of determining whether or not the origin of the delay was in the comparison between SYNTH_ARG_UDISKSSERIAL and data->serial made in the callback uevent_probed_cb, as it has been proved. Of course, once out into the open, it must be fixed either in vdev or libudev-compat. I've been trying to find the origin of the issue through other projects like glib2.0, gvfs, dbus or maybe some udev rule not translated into a vdev action yet. And believe me, it has been like looking for a needle in a haystack.

[gnuinos]

I understand... You are tagging the user event in the callback trigger_uevent_idle_cb through the function:

trigger_uevent (data-uevent_path, str)

where:

str = g_strdup_printf ("change %s UDISKSSERIAL=%u", udisks_daemon_get_uuid (data->daemon), data->serial)

following the format ACTION [UUID [KEY=VALUE ...] specified in the linux docs:

https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=f36776fafbaa0094390dd4e7e3e29805e0b82730

Eudev does receive this change from netlink, but vdev somehow ends up losing it.

[gnuinos]

The solution won't be very difficult. I can see these synthetic variables when running vdev in debug mode:

( ... preceding output snipped... )
22135:00007F37518796C0: [ action.c:0654] vdev_action_run_sync: DEBUG: command env: VDEV_OS_SUBSYSTEM=block
22135:00007F37518796C0: [ action.c:0654] vdev_action_run_sync: DEBUG: command env: VDEV_OS_SYNTH_ARG_UDISKSSERIAL=0
22135:00007F37518796C0: [ action.c:0654] vdev_action_run_sync: DEBUG: command env: VDEV_OS_SYNTH_UUID=a16247e1-46e7-477d-a411-fbf7499f95e6
22135:00007F37518796C0: [ action.c:0654] vdev_action_run_sync: DEBUG: command env: VDEV_OS_SYSFS_MOUNTPOINT=/sys
22135:00007F37518796C0: [ action.c:0659] vdev_action_run_sync: DEBUG: exit status 0
22135:00007F37518796C0: [ action.c:1734] vdev_action_run_commands: DEBUG: Benchmark: action /etc/vdev/actions/zzz-udev-compat.act succeeded in 42 millis

[gnuinos]

I've just fixed the issue doing some minor changes in the vdev helpers. Thanks.

[tbzatek]

Great, that's the right way to go! Thanks.

[gnuinos]

I learnt something new by being involved in this discussion.