Bug 1733814 - Attempting to benchmark disc terminates udisks2
Summary: Attempting to benchmark disc terminates udisks2
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: udisks2
Version: 35
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
Assignee: Tomáš Bžatek
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-07-28 22:07 UTC by James
Modified: 2022-12-13 15:13 UTC (History)
4 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2022-12-13 15:13:16 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
udevadm info -e output (250.39 KB, text/plain)
2021-11-05 12:24 UTC, James
no flags Details

Description James 2019-07-28 22:07:14 UTC
Description of problem:
Attempting to benchmark a device using Gnome Disks causes udisks2 to SIGTERM.

Version-Release number of selected component (if applicable):
udisks2-2.8.2-1.fc30.x86_64
gnome-disk-utility-3.32.1-2.fc30.x86_64

How reproducible:
Always.

Steps to Reproduce:
1. Attach/insert device to benchmark (in this particular case an SD card on /dev/mmcblk0).
2. Open Gnome Disks.
3. Select the device, open Benchmark.
4. Click Start Benchmark, then Start Benchmarking.
5. Enter admin password when prompted.

Actual results:
Message box 'Remote peer disconnected (g-dbus-error-quark, 4)'.

In the system journal: 'udisks2.service: Main process exited, code=killed, status=15/TERM'

udisks2 is dead at this point -- newly-attached devices aren't noticed, at least until Gnome Disks is restarted.

Expected results:
Benchmark begins. Other disks and udisks2 operations unaffected.

Comment 1 Tomáš Bžatek 2019-07-29 08:53:58 UTC
Please retest with https://bodhi.fedoraproject.org/updates/FEDORA-2019-65574a0e7a

Comment 2 James 2019-07-29 19:41:01 UTC
Still present with

udisks2-2.8.4-1.fc30.x86_64
libudisks2-2.8.4-1.fc30.x86_64
udisks2-iscsi-2.8.4-1.fc30.x86_64

Comment 3 Tomáš Bžatek 2019-07-30 07:16:52 UTC
Interesting, thanks for the test. Could you try finding related udisks2.service messages within the system journal? Something that would indicate an error. Alternatively please have a look at the output of coredumpctl if there's a coredump of udisksd and attach a backtrace here if so.

Comment 4 James 2019-07-30 07:31:31 UTC
Can't see anything incriminating in journalctl -u udisks2. When I ran udisksd -d on the console all I got was:

udisks-Message: 08:21:51.191: udisks daemon version 2.8.4 starting
udisks-Message: 08:21:51.474: Acquired the name org.freedesktop.UDisks2 on the system message bus
Terminated

Nothing in coredumpctl. I tried under gdb but got nothing more than the above.

Comment 5 Ben Cotton 2020-04-30 21:27:46 UTC
This message is a reminder that Fedora 30 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 30 on 2020-05-26.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '30'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 30 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 6 Alex Villacís Lasso 2020-05-16 21:51:49 UTC
This bug persists in Fedora 32 Live ISO when attempting to benchmark an internal drive on an M-Book Speedmind netbook.

Comment 7 Tomáš Bžatek 2020-05-18 10:07:33 UTC
(In reply to Alex Villacís Lasso from comment #6)
> This bug persists in Fedora 32 Live ISO when attempting to benchmark an
> internal drive on an M-Book Speedmind netbook.

Great! Can you please grab a backtrace and post it here? Please check `coredumpctl` if there were any crashes. Also ABRT I think could be useful here.

Comment 8 James 2020-08-17 16:30:00 UTC
I'm not currently seeing this with udisks2-2.8.4-4.fc32 -- how about you Alex?

Comment 9 Alex Villacís Lasso 2020-08-17 16:50:37 UTC
I am still experiencing this with udisks2-2.8.4-4.fc32 . In my case, the block device is an internal flash device that shows up as a SD card reader, yet is the device from which the system boots up.

Comment 10 Alex Villacís Lasso 2020-08-17 16:58:14 UTC
BTW, there is absolutely no mention of udiskd crashing at all from the coredumpctl listing, or any ABRT report. It looks as if the program simply decides to terminate normally.

Comment 11 Alex Villacís Lasso 2020-08-17 17:00:43 UTC
I have reproduced this with a different card reader, that shows up as /dev/mmcblk1. The boot device shows up as /dev/mmcblk0. But card readers exposed via USB that show up as /dev/sdX do NOT trigger the bug.

Comment 12 Fedora Program Management 2021-04-29 16:50:36 UTC
This message is a reminder that Fedora 32 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 32 on 2021-05-25.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '32'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 32 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 13 Alex Villacís Lasso 2021-04-29 18:18:48 UTC
This bug STILL persists in Fedora 34 x86_64 on the very same M-Book Speedmind netbook with the /dev/mmcblk0 device I am trying to benchmark.

The gnome-disks GUI just shows a popup with the following message:

  Remote peer disconnected (g-dbus-error-quark, 4)

Meanwhile, journalctl -f shows the following log message when the situation happens (and NO OTHER BACKTRACE):

  udisks2.service: Deactivated successfully

After this, as before, gnome-disks is unable to show any devices or do any operation until restarted - it shows no devices at all.

The device NEEDS to be of type /dev/mmcblkX to trigger the bug - /dev/sdX devices work correctly.

@James Please change the Version field to 34, as I am unable to.

Comment 14 James 2021-11-03 22:15:03 UTC
Bumping version to 35. Still present in udisks2-2.9.4-1.fc35.x86_64 as described above, with mmcblk devices. Still no indication of why, nothing in coredumpctl.

Comment 15 Tomáš Bžatek 2021-11-04 11:32:55 UTC
Okay, can you please provide backtrace of the crash? See coredumpctl.

Comment 16 Tomáš Bžatek 2021-11-04 11:33:35 UTC
Or, just attach gdb to a running udisksd process, let it continue and wait for a crash.

Comment 17 James 2021-11-04 13:31:57 UTC
I think this is SELinux related. It's OK in Permissive mode, but nothing shows up in the audit logs as to why.

From gdb attached to the running udisksd:

(gdb) bt
#0  0x00007f521bdf77ff in __GI___poll (fds=0x556ee8a297a0, nfds=6, timeout=599992) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007f521bfc021c in g_main_context_poll
    (priority=<optimized out>, n_fds=6, fds=0x556ee8a297a0, timeout=<optimized out>, context=0x556ee89a21a0)
    at ../glib/gmain.c:4478
#2  g_main_context_iterate.constprop.0
    (context=0x556ee89a21a0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/gmain.c:4170
#3  0x00007f521bf6a903 in g_main_loop_run (loop=0x556ee899d830) at ../glib/gmain.c:4373
#4  0x0000556ee792956b in main (argc=<optimized out>, argv=<optimized out>)
    at /usr/src/debug/udisks2-2.9.4-1.fc35.x86_64/src/main.c:184
(gdb) c
Continuing.

At this point I start the benchmark.

[New Thread 0x7f521ac81640 (LWP 85220)]
[Detaching after fork from child process 85245]
[Thread 0x7f521ac81640 (LWP 85220) exited]
[New Thread 0x7f521ac81640 (LWP 85287)]

Thread 1 "udisksd" received signal SIGTERM, Terminated.
__pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=15, no_tid=no_tid@entry=0) at pthread_kill.c:44
44	      return INTERNAL_SYSCALL_ERROR_P (ret) ? INTERNAL_SYSCALL_ERRNO (ret) : 0;

And that's it. Backtrace at this point is

#0  __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=15, no_tid=no_tid@entry=0) at pthread_kill.c:44
#1  0x00007f500a7d48c3 in __pthread_kill_internal (signo=15, threadid=<optimized out>) at pthread_kill.c:78
#2  0x00007f500a7876b6 in __GI_raise (sig=15) at ../sysdeps/posix/raise.c:26
#6  0x00007f500aad5b33 in <emit signal ??? on instance ???>
    (instance=<optimized out>, signal_id=<optimized out>, detail=detail@entry=0) at ../gobject/gsignal.c:3553
    #3  0x00007f500aab7c2f in g_closure_invoke
    (closure=0x55b66e3ca3e0, return_value=0x0, n_param_values=3, param_values=0x7ffd724f9760, invocation_hint=0x7ffd724f96e0)
    at ../gobject/gclosure.c:830
    #4  0x00007f500aad3a44 in signal_emit_unlocked_R
    (node=node@entry=0x55b66e3ca430, detail=detail@entry=0, instance=instance@entry=0x55b66e3d1050, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffd724f9760) at ../gobject/gsignal.c:3781
    #5  0x00007f500aad591a in g_signal_emit_valist
    (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffd724f9940)
    at ../gobject/gsignal.c:3497
#7  0x00007f500ac00e26 in emit_closed_in_idle (user_data=user_data@entry=0x7f5000007d60) at ../gio/gdbusconnection.c:1388
#8  0x00007f500a9ba52b in g_idle_dispatch
    (source=0x7f500000a1b0, callback=0x7f500ac00dd0 <emit_closed_in_idle>, user_data=0x7f5000007d60) at ../glib/gmain.c:5897
#9  0x00007f500a9be33f in g_main_dispatch (context=0x55b66e3c11a0) at ../glib/gmain.c:3381
#10 g_main_context_dispatch (context=0x55b66e3c11a0) at ../glib/gmain.c:4099
#11 0x00007f500aa13288 in g_main_context_iterate.constprop.0
    (context=0x55b66e3c11a0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/gmain.c:4175
#12 0x00007f500a9bd903 in g_main_loop_run (loop=0x55b66e3bc830) at ../glib/gmain.c:4373
#13 0x000055b66c4e456b in main (argc=<optimized out>, argv=<optimized out>)
    at /usr/src/debug/udisks2-2.9.4-1.fc35.x86_64/src/main.c:184

strace attached to a udisksd, when attempting a mmcblk benchmark:

strace: Process 86916 attached
restart_syscall(<... resuming interrupted read ...>) = 1
read(4, "\1\0\0\0\0\0\0\0", 16)         = 8
rt_sigprocmask(SIG_BLOCK, ~[], [], 8)   = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f7a95c46910, parent_tid=0x7f7a95c46910, exit_signal=0, stack=0x7f7a95446000, stack_size=0x7ffd40, tls=0x7f7a95c46640} => {parent_tid=[86985]}, 88) = 86985
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0x5563d09b0aa0, FUTEX_WAKE_PRIVATE, 1) = 1
poll([{fd=4, events=POLLIN}, {fd=8, events=0}, {fd=9, events=0}, {fd=11, events=POLLIN}, {fd=13, events=POLLIN}, {fd=14, events=0}], 6, 580360) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\2\0\0\0\0\0\0\0", 16)         = 8
write(4, "\1\0\0\0\0\0\0\0", 8)         = 8
futex(0x5563d09ae1b0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
gettid()                                = 86916
getpid()                                = 86916
tgkill(86916, 86916, SIGTERM)           = 0
--- SIGTERM {si_signo=SIGTERM, si_code=SI_TKILL, si_pid=86916, si_uid=0} ---
+++ killed by SIGTERM +++

Comment 18 Tomáš Bžatek 2021-11-04 14:05:26 UTC
Hmm, the "emit_closed_in_idle()" frame is called from a GDBus implementation when a bus connection is lost. Either some other udisksd instance has replaced this running one, or something external forcefully closed the D-Bus connection or the daemon is just shutting down. Nothing related to the benchmark/read functionality.

Is there anything related logged via `systemctl status udisks2.service`? Any reason to respawn the service?

Also, are you trying to benchmark the drive itself or a partition like /dev/mmcblk0pX? MMC devices are rather special with those separate boot areas and a key store area.

Comment 19 James 2021-11-04 17:24:26 UTC
This is systemctl status immediately after udisks2 exits when attempting to benchmark:

# systemctl status udisks2.service 
○ udisks2.service - Disk Manager
     Loaded: loaded (/usr/lib/systemd/system/udisks2.service; enabled; vendor preset: enabled)
     Active: inactive (dead) since Thu 2021-11-04 17:18:57 GMT; 2s ago
       Docs: man:udisks(8)
    Process: 100688 ExecStart=/usr/libexec/udisks2/udisksd (code=killed, signal=TERM)
   Main PID: 100688 (code=killed, signal=TERM)
        CPU: 58ms

Nov 04 17:18:43 dante.cb.ettle systemd[1]: Starting Disk Manager...
Nov 04 17:18:43 dante.cb.ettle udisksd[100688]: udisks daemon version 2.9.4 starting
Nov 04 17:18:43 dante.cb.ettle systemd[1]: Started Disk Manager.
Nov 04 17:18:43 dante.cb.ettle udisksd[100688]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Nov 04 17:18:57 dante.cb.ettle systemd[1]: udisks2.service: Deactivated successfully.

As far as I'm aware the service isn't respawning. It's terminated and stays like that until manually started again.

The benchmarked block device is whatever the GNOME Disks utility is giving it when the card reader (rtsx_pci) is selected, and Benchmark Disk is chosen from the '3 vertical dots' menu on the headerbar. Judging from the Benchmark window, it's using the basic physical device /dev/mmcblk0.

Comment 20 Tomáš Bžatek 2021-11-05 12:06:27 UTC
(In reply to James from comment #19)

Thanks, nothing suspicious there unfortunately, except the "deactivation".

> As far as I'm aware the service isn't respawning. It's terminated and stays
> like that until manually started again.

That's not really a problem, it will get seamlessly autostarted by next D-Bus call.

> The benchmarked block device is whatever the GNOME Disks utility is giving
> it when the card reader (rtsx_pci) is selected, and Benchmark Disk is chosen
> from the '3 vertical dots' menu on the headerbar. Judging from the Benchmark
> window, it's using the basic physical device /dev/mmcblk0.

Right, that's what I've been looking for - the mmcblk devices are not strictly block devices. Does the benchmarking work when you try benchmarking a partition? That's the "Benchmark Partition..." command after clicking the gear button with a partition selected.

A side request - could you please attach `udevadm info -e` output?

Another experiment perhaps: does `dd if=/dev/mmcblk0 of=/dev/null` work for you in Enforcing mode? Although this is run with a different SELinux context, likely unconfined, still any I/O errors may occur.

I've tried to find any way of emulating a mmcblk device for our tests but couldn't find anything useful. As we have no sd/sdio/mmc devices available, it makes debugging rather difficult.

Comment 21 James 2021-11-05 12:24:02 UTC
(In reply to Tomáš Bžatek from comment #20)
> Right, that's what I've been looking for - the mmcblk devices are not
> strictly block devices. Does the benchmarking work when you try benchmarking
> a partition? That's the "Benchmark Partition..." command after clicking the
> gear button with a partition selected.

Same result, udisksd terminates.

> A side request - could you please attach `udevadm info -e` output?

Will be attached to next message.

> Another experiment perhaps: does `dd if=/dev/mmcblk0 of=/dev/null` work for
> you in Enforcing mode? Although this is run with a different SELinux
> context, likely unconfined, still any I/O errors may occur.

I observed no I/O errors with this.

Comment 22 James 2021-11-05 12:24:40 UTC
Created attachment 1840151 [details]
udevadm info -e output

Comment 23 Ben Cotton 2022-11-29 16:46:33 UTC
This message is a reminder that Fedora Linux 35 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora Linux 35 on 2022-12-13.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
'version' of '35'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, change the 'version' 
to a later Fedora Linux version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora Linux 35 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora Linux, you are encouraged to change the 'version' to a later version
prior to this bug being closed.

Comment 24 Alex Villacís Lasso 2022-11-29 17:16:30 UTC
Still happening on Fedora 36 AND Fedora 37 after applying all upgrades.

Comment 25 Ben Cotton 2022-12-13 15:13:16 UTC
Fedora Linux 35 entered end-of-life (EOL) status on 2022-12-13.

Fedora Linux 35 is no longer maintained, which means that it
will not receive any further security or bug fix updates. As a result we
are closing this bug.

If you can reproduce this bug against a currently maintained version of Fedora Linux
please feel free to reopen this bug against that version. Note that the version
field may be hidden. Click the "Show advanced fields" button if you do not see
the version field.

If you are unable to reopen this bug, please file a new report against an
active release.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.