Description of problem: Crash occured during dnf upgrade process Version-Release number of selected component: dbus-broker-20-2.fc31 Additional info: reporter: libreport-2.10.0 backtrace_rating: 4 cmdline: /usr/bin/dbus-broker-launch --scope user crash_function: service_activate executable: /usr/bin/dbus-broker-launch journald_cursor: s=4595384b0fa54b3b8b5f9a8679d25aae;i=1743;b=105736afd22746eaa826c4fd21f08165;m=42fac1e2;t=586aa16cbaa27;x=f3cf24e92603fd8f kernel: 5.1.0-0.rc5.git0.1.fc31.x86_64 rootdir: / runlevel: N 5 type: CCpp uid: 1000 Truncated backtrace: Thread no. 1 (10 frames) #4 service_activate at ../src/launch/service.c:373 #5 launcher_on_name_activate at ../src/launch/launcher.c:405 #6 launcher_on_message at ../src/launch/launcher.c:496 #7 process_filter at ../src/libsystemd/sd-bus/sd-bus.c:2598 #8 process_message at ../src/libsystemd/sd-bus/sd-bus.c:2734 #9 process_running at ../src/libsystemd/sd-bus/sd-bus.c:2788 #10 bus_process_internal at ../src/libsystemd/sd-bus/sd-bus.c:3005 #11 io_callback at ../src/libsystemd/sd-bus/sd-bus.c:3383 #12 source_dispatch at ../src/libsystemd/sd-event/sd-event.c:2821 #13 sd_event_dispatch at ../src/libsystemd/sd-event/sd-event.c:3234
Created attachment 1555635 [details] File: backtrace
Created attachment 1555636 [details] File: cgroup
Created attachment 1555637 [details] File: core_backtrace
Created attachment 1555638 [details] File: cpuinfo
Created attachment 1555639 [details] File: dso_list
Created attachment 1555640 [details] File: environ
Created attachment 1555641 [details] File: limits
Created attachment 1555642 [details] File: maps
Created attachment 1555643 [details] File: mountinfo
Created attachment 1555644 [details] File: open_fds
Created attachment 1555645 [details] File: proc_pid_status
Dying here too. systemctl status dbus-broker.service says: ● dbus-broker.service - D-Bus System Message Bus Loaded: loaded (/usr/lib/systemd/system/dbus-broker.service; enabled; vendor preset: enabled) Active: failed (Result: exit-code) since Tue 2019-04-16 15:07:16 EDT; 29min ago Docs: man:dbus-broker-launch(1) Process: 1122 ExecStart=/usr/bin/dbus-broker-launch --scope system --audit (code=exited, status=1/FAILURE) Main PID: 1122 (code=exited, status=1/FAILURE) Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: ERROR launcher_run @ ../src/launch/launcher.c +1358: Invalid argument Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: run @ ../src/launch/main.c +153 Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: main @ ../src/launch/main.c +181 Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: Exiting due to fatal error: -22 Apr 16 15:07:16 turing-police systemd[1]: dbus-broker.service: Main process exited, code=exited, status=1/FAILURE Rolling back to version 19 makes things work again.
Gaah. Forgot to note that 'dnf update' worked (or seemed to), but things went sideways at next reboot due to lack of dbus.
(In reply to Valdis Kletnieks from comment #12) > Dying here too. systemctl status dbus-broker.service says: > > ● dbus-broker.service - D-Bus System Message Bus > Loaded: loaded (/usr/lib/systemd/system/dbus-broker.service; enabled; > vendor preset: enabled) > Active: failed (Result: exit-code) since Tue 2019-04-16 15:07:16 EDT; > 29min ago > Docs: man:dbus-broker-launch(1) > Process: 1122 ExecStart=/usr/bin/dbus-broker-launch --scope system --audit > (code=exited, status=1/FAILURE) > Main PID: 1122 (code=exited, status=1/FAILURE) > > Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: ERROR launcher_run @ > ../src/launch/launcher.c +1358: Invalid argument > Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: run @ > ../src/launch/main.c +153 > Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: main @ > ../src/launch/main.c +181 > Apr 16 15:07:16 turing-police dbus-broker-launch[1122]: Exiting due to fatal > error: -22 > Apr 16 15:07:16 turing-police systemd[1]: dbus-broker.service: Main process > exited, code=exited, status=1/FAILURE > > Rolling back to version 19 makes things work again. This is `sd_bus_add_object_vtable()` returning -EINTR during startup. The arguments to `sd_bus_add_object_vtable()` are all constant statics, so this is unlikely to be due to a change in `dbus-broker`. I went ahead and checked systemd changes. There was a recent systemd-242 release, handful of days ago, which happened to be pushed into rawhide at the same time as `dbus-broker-20`. The new systemd-242 release brings API changes to the sd-bus VTABLE logic. But before I dive into this, can you answer me some questions? - Are you running rawhide or F30? - Did you skip updates to any other package than `dbus-broker`? That is, did you happen to postpone the systemd-242 update? - What architecture do you run this on? I will discuss the vtable changes with systemd people later today. I suspect they forgot to bump some symbol-versions. Regardless, I am quite confident this is a different issue than the original bug in this issue. Thanks! David
(In reply to Mikhail from comment #0) > Description of problem: > Crash occured during dnf upgrade process > > Version-Release number of selected component: > dbus-broker-20-2.fc31 > > Additional info: > reporter: libreport-2.10.0 > backtrace_rating: 4 > cmdline: /usr/bin/dbus-broker-launch --scope user > crash_function: service_activate > executable: /usr/bin/dbus-broker-launch > journald_cursor: > s=4595384b0fa54b3b8b5f9a8679d25aae;i=1743;b=105736afd22746eaa826c4fd21f08165; > m=42fac1e2;t=586aa16cbaa27;x=f3cf24e92603fd8f > kernel: 5.1.0-0.rc5.git0.1.fc31.x86_64 > rootdir: / > runlevel: N 5 > type: CCpp > uid: 1000 > > Truncated backtrace: > Thread no. 1 (10 frames) > #4 service_activate at ../src/launch/service.c:373 > #5 launcher_on_name_activate at ../src/launch/launcher.c:405 > #6 launcher_on_message at ../src/launch/launcher.c:496 > #7 process_filter at ../src/libsystemd/sd-bus/sd-bus.c:2598 > #8 process_message at ../src/libsystemd/sd-bus/sd-bus.c:2734 > #9 process_running at ../src/libsystemd/sd-bus/sd-bus.c:2788 > #10 bus_process_internal at ../src/libsystemd/sd-bus/sd-bus.c:3005 > #11 io_callback at ../src/libsystemd/sd-bus/sd-bus.c:3383 > #12 source_dispatch at ../src/libsystemd/sd-event/sd-event.c:2821 > #13 sd_event_dispatch at ../src/libsystemd/sd-event/sd-event.c:3234 I found a bug in the state-tracking of service-entries. I proposed a fix [1]. Note, however, that this can only be triggered if reloading of the bus configuration fails. It would thus be interesting to see the log-messages why this failed. Thanks! David [1] https://github.com/bus1/dbus-broker/pull/200
(In reply to David Rheinsberg from comment #14) > But before I dive into this, can you answer me some questions? > > - Are you running rawhide or F30? Rawhide. > - Did you skip updates to any other package than `dbus-broker`? That is, > did you happen to postpone the systemd-242 update? I did a 'dnf update', which did *not* pick up systemd-242. Turns out that I had 'exclude = systemd*' in dnf.conf (for a different problem a few months ago). In case it matters: rpm -qi systemd Name : systemd Version : 241~rc2 Release : 2.fc30 Architecture: x86_64 Install Date: Tue 12 Feb 2019 08:58:33 PM EST So I do the 'dnf update', next day reboot, and dbus is broken. Revert dbus 1.12.12-7 update back to -6, still broken. Revert glibc (next most obvious suspect), still broken. Noticed that dbus-broker wasn't part of dbus, revert that, started working. > - What architecture do you run this on? x86_64 on a Toshiba laptop. (Should I open a different bug report on this?)
dbus-broker-20-4.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-7b1733dc68
I had quite some issues with dbus-broker when updating my Rawhide installation, but I thought selinux-policy is to be blamed: [bug 1699911]. It is possible that dbus-broker just got to the unexpected condition and did weird stuff, which only then consequently triggered SELinux related AVCs, but I think selinux-policy should accommodate to whatever non-malicious behaviours program can normally exhibit, hence that bug is still possibly valid regardless -- only close that if it is known to be the actual misbehaviour of dbus-broker. Anyway, I put my hands from updating dbus-broker for some time now until the watermark disappears, since recovering can be rather time inefficient in the bad cases.
dbus-broker-20-4.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-7b1733dc68
Created attachment 1556295 [details] system log (In reply to David Rheinsberg from comment #15) > I found a bug in the state-tracking of service-entries. I proposed a fix > [1]. Note, however, that this can only be triggered if reloading of the bus > configuration fails. It would thus be interesting to see the log-messages > why this failed. I am attached system logs because it crashed again. $ rpm -q dbus-broker dbus-broker-20-4.fc31.x86_64
(In reply to Valdis Kletnieks from comment #16) > (In reply to David Rheinsberg from comment #14) > > > But before I dive into this, can you answer me some questions? > > > > - Are you running rawhide or F30? > > Rawhide. > > > - Did you skip updates to any other package than `dbus-broker`? That is, > > did you happen to postpone the systemd-242 update? > > I did a 'dnf update', which did *not* pick up systemd-242. Turns out that > I had 'exclude = systemd*' in dnf.conf (for a different problem a few months > ago). In case it matters: > > rpm -qi systemd > Name : systemd > Version : 241~rc2 > Release : 2.fc30 > Architecture: x86_64 > Install Date: Tue 12 Feb 2019 08:58:33 PM EST > > So I do the 'dnf update', next day reboot, and dbus is broken. > Revert dbus 1.12.12-7 update back to -6, still broken. > Revert glibc (next most obvious suspect), still broken. > Noticed that dbus-broker wasn't part of dbus, revert that, started working. > > > - What architecture do you run this on? > > x86_64 on a Toshiba laptop. > > (Should I open a different bug report on this?) So yeah, leaving the `systemd` update behind actually triggered a bug in the most recent systemd-242 release. I reported this and discussed it last week with the systemd developers. There is a pending fix on github and this will be pushed into Fedora. Until then, Zbigniew might just revert the breaking changes in rawhide, but I am not sure about this. For details, see: https://github.com/systemd/systemd/pull/12351 As a summary: systemd-242 updates `libsystemd`, but unintentionally breaks symbol-versioning and auto-detection of dependencies in `rpm`. This is quite non-obvious, but packages compiled against systemd-242 (which happens to be the current rawhide version) will not run properly against any older systemd version.
(In reply to Mikhail from comment #20) > Created attachment 1556295 [details] > system log > > (In reply to David Rheinsberg from comment #15) > > I found a bug in the state-tracking of service-entries. I proposed a fix > > [1]. Note, however, that this can only be triggered if reloading of the bus > > configuration fails. It would thus be interesting to see the log-messages > > why this failed. > > I am attached system logs because it crashed again. > > $ rpm -q dbus-broker > dbus-broker-20-4.fc31.x86_64 Your log contains this: 14959 Apr 19 08:11:45 localhost.localdomain dbus-broker-launch[2128]: dbus-broker-launch: ../src/launch/service.c:506: service_activate: Assertion `c_assert_result && "service->state == SERVICE_ST ATE_CURRENT"' failed. ...which is odd, because dbus-broker-20-4 includes a patch that drops this assertion. The entire "state" member field is dropped: https://src.fedoraproject.org/rpms/dbus-broker/c/283e44851e596cc684885ed374b5485c10dc24af?branch=master Did you actually reboot after updating dbus-broker? Note that the system bus is not restarted with live-updates. Either your system was still running on the old dbus-broker binary, or the RPM package update somehow does not apply the patch correctly. Anyway, your log also contains this: 11952 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: Noticed file-system modification, trigger reload. 11953 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: ERROR dirwatch_add @ ../src/util/dirwatch.c +122: No space left on device 11954 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: config_parser_end_fn @ ../src/launch/config.c +1068 11955 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: config_parser_include @ ../src/launch/config.c +1282 11956 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: config_parser_read @ ../src/launch/config.c +1334 11957 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: launcher_parse_config @ ../src/launch/launcher.c +1016 11958 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: launcher_reload_config @ ../src/launch/launcher.c +1231 11959 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: launcher_on_dirwatch @ ../src/launch/launcher.c +153 This is the *user-bus* on your system, which aborted operation because it was unable to install inotify-watches. Since the user-bus runs as the same UID as your entire user-session, it means the resources are all shared. There is definitely something on your system that consumes inotify-watches, and a lot of them. Not sure what we can do about it. We could ignore this and try to continue, but that would just be putting paper-bags over bugs.
For what it's worth, I'm now on systemd-242-2.fc31.x86_64, dbus-1.12.12-7.fc31.x86_64, and dbus-broker-20-4.fc31.x86_64 and my laptop is again performing nominally.
(In reply to David Rheinsberg from comment #22) > > Your log contains this: > > 14959 Apr 19 08:11:45 localhost.localdomain dbus-broker-launch[2128]: > dbus-broker-launch: ../src/launch/service.c:506: service_activate: Assertion > `c_assert_result && "service->state == SERVICE_ST ATE_CURRENT"' failed. > > ...which is odd, because dbus-broker-20-4 includes a patch that drops this > assertion. The entire "state" member field is dropped: > > > https://src.fedoraproject.org/rpms/dbus-broker/c/ > 283e44851e596cc684885ed374b5485c10dc24af?branch=master > > Did you actually reboot after updating dbus-broker? Note that the system bus > is not restarted with live-updates. Either your system was still running on > the old dbus-broker binary, or the RPM package update somehow does not apply > the patch correctly. Actualy I did not have time to reboot. After dnf upgrade (dbus-broker-20-3 -> dbus-broker-20-4) I was begun close applications, but gnome session terminated earlier than i had time to close all applications. And after logon I was saw that dbus-broker crashed again. > Anyway, your log also contains this: > > 11952 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > Noticed file-system modification, trigger reload. > > 11953 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: ERROR > dirwatch_add @ ../src/util/dirwatch.c +122: No space left on device > 11954 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > config_parser_end_fn @ ../src/launch/config.c +1068 > 11955 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > config_parser_include @ ../src/launch/config.c +1282 > 11956 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > config_parser_read @ ../src/launch/config.c +1334 > 11957 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > launcher_parse_config @ ../src/launch/launcher.c +1016 > 11958 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > launcher_reload_config @ ../src/launch/launcher.c +1231 > 11959 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > launcher_on_dirwatch @ ../src/launch/launcher.c +153 > > This is the *user-bus* on your system, which aborted operation because it > was unable to install inotify-watches. Since the user-bus runs as the same > UID as your entire user-session, it means the resources are all shared. > There is definitely something on your system that consumes inotify-watches, > and a lot of them. Not sure what we can do about it. We could ignore this > and try to continue, but that would just be putting paper-bags over bugs. It means that any malicious application can break the system?
(In reply to Mikhail from comment #24) > (In reply to David Rheinsberg from comment #22) > > Anyway, your log also contains this: > > > > 11952 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > Noticed file-system modification, trigger reload. > > > > 11953 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: ERROR > > dirwatch_add @ ../src/util/dirwatch.c +122: No space left on device > > 11954 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > config_parser_end_fn @ ../src/launch/config.c +1068 > > 11955 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > config_parser_include @ ../src/launch/config.c +1282 > > 11956 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > config_parser_read @ ../src/launch/config.c +1334 > > 11957 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > launcher_parse_config @ ../src/launch/launcher.c +1016 > > 11958 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > launcher_reload_config @ ../src/launch/launcher.c +1231 > > 11959 Apr 19 08:03:23 localhost.localdomain dbus-broker-launch[2128]: > > launcher_on_dirwatch @ ../src/launch/launcher.c +153 > > > > This is the *user-bus* on your system, which aborted operation because it > > was unable to install inotify-watches. Since the user-bus runs as the same > > UID as your entire user-session, it means the resources are all shared. > > There is definitely something on your system that consumes inotify-watches, > > and a lot of them. Not sure what we can do about it. We could ignore this > > and try to continue, but that would just be putting paper-bags over bugs. > > It means that any malicious application can break the system? Almost. `It means that any malicious application can break your session.` If you run a malicious application as UID 1000, it can break anything that runs as UID 1000, unless you sufficiently sandbox the malicious application. Thanks David
*** Bug 1703611 has been marked as a duplicate of this bug. ***
Proposed as a Freeze Exception for 30-final by Fedora user tomegun using the blocker tracking app because: When the bug triggers the system and/or user bus will crash. The bug can only be triggered when the configuration is reloaded while invalid. One situation this may happen in is during dnf upgrade, as starting to write new configuration will trigger a reload via inotify and partially written configuration may be invalid. The pending package in testing fixes the problem.
We already signed off the release.
dbus-broker-20-4.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.