Bug 1592818 - Ocasionally fails to start with "dbus-broker-launch[xxx]: No listener socket inherited""
Summary: Ocasionally fails to start with "dbus-broker-launch[xxx]: No listener socket ...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: dbus-broker
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Tom Gundersen
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-06-19 11:27 UTC by Yanko Kaneti
Modified: 2018-08-30 03:51 UTC (History)
4 users (show)

Fixed In Version: dbus-broker-15-2.fc28 dbus-broker-15-2.fc27
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-07-04 11:45:07 UTC
Type: Bug


Attachments (Terms of Use)

Description Yanko Kaneti 2018-06-19 11:27:22 UTC
Description of problem:
Every now and then dbus-broker fails to start. eg:
..
systemd[1]: Starting D-Bus System Message Bus...
dbus-broker-launch[645]: No listener socket inherited
systemd[1]: dbus-broker.service: Main process exited, code=exited, status=1/FAILURE
systemd[1]: dbus-broker.service: Failed with result 'exit-code'.
systemd[1]: Failed to start D-Bus System Message Bus.
..


Version-Release number of selected component (if applicable):
dbus-broker-13-1.fc29.x86_64


How reproducible:
Sometimes it happens two or three times in a row, then then next reboot its ok.


$ uname -r
4.18.0-0.rc1.git0.1.fc29.x86_64
$ rpm -q systemd
systemd-238-8.git0e0aa59.fc29.x86_64
$ sestatus 
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   permissive
Mode from config file:          permissive
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Memory protection checking:     actual (secure)
Max kernel policy version:      31

Comment 1 David Herrmann 2018-06-20 08:25:30 UTC
Wow. This is... weird. So the error message you trigger happens if `sd_listen_fds(3)` returns 0. This happens in the following scenarios:

 - LISTEN_PID is not set
 - LISTEN_FDS is not set
 - LISTEN_PID does not match the pid of the caller

In all other cases, `sd_listen_fds(3)` returns an error.

I can now imagine several bugs that trigger this:

 - dbus-broker has some memory corruption that just triggers this behavior.
 - systemd is buggy and sets an incorrect socket-activation environment.
 - The PID-matching in `sd_listen_fds(3)` is buggy.
 - dbus.socket is for some reason not pulled in.

TBH, the first two options are possible, but why nobody else notice it, and why would it only affect your sd_listen_fds() call? I will do some valgrind runs and audit that code, but it seems unlikely to me.

The third option is also unlikely. There is some special code involved, since systemd does pid-caching via atfork handlers. But that looks all clean, and I cannot see how we would be affected by this.

So I am left to assume the last option. Can you add 'Requires=dbus.socket' to /usr/lib/systemd/system/dbus-broker.service? It belongs in the [Unit] section. I suspect there is some service that pulls in dbus.service directly, without pulling in the socket.

Comment 2 Yanko Kaneti 2018-06-20 10:07:57 UTC
Weird indeed.  

After your comment and without modifying the service Requires I tried to provoke the failure by rebooting, resetting, power cycling  at least 10 times.  
All with the same kernel and systemd and unfortunately without any failure.

For now I'll assume something transient and rawhide specific and set this to NEEDINFO (from me or anyone that might've encountered this) and wait for it to happen again.

Comment 3 David Rheinsberg 2018-06-29 09:56:47 UTC
(In reply to Yanko Kaneti from comment #2)
> After your comment and without modifying the service Requires I tried to
> provoke the failure by rebooting, resetting, power cycling  at least 10
> times.  
> All with the same kernel and systemd and unfortunately without any failure.

Yeah, I couldn't reproduce it either. Might have been some temporary error due to live-updates, rawhide-stuff, etc. Not sure.

However, I did spend some time tracing this and I think I found the culprit. So we incorrectly assumed that 'dbus.service' pulls in 'dbus.socket', but that's not the case. So if *any* unit activates 'dbus.service' early (before 'dbus.socket' is activated), it might get started without socket activation and thus trigger this error you saw. I fixed this now (upcoming in the next release), 'dbus.service' now pulls in 'dbus.socket' so socket activation is always performed.

Question still is: Who would pull in 'dbus.service' so early that 'dbus.socket' is not around, yet? I mean, 'dbus.socket' is ready *before* 'basic.target', so this sounds to me like some temporary misconfiguration in some unit. But at least with my fix this should not be an issue, anymore.
 
> For now I'll assume something transient and rawhide specific and set this to
> NEEDINFO (from me or anyone that might've encountered this) and wait for it
> to happen again.

I will close this bug now. Please feel free to re-open if you have more questions or feel like this is unsatisfactory.

Thanks a lot for the report!
David

Comment 4 Fedora Update System 2018-07-03 21:59:22 UTC
dbus-broker-14-1.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-d278b029e6

Comment 5 Fedora Update System 2018-07-03 21:59:29 UTC
dbus-broker-14-1.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-69fe428f56

Comment 6 Fedora Update System 2018-07-04 16:23:37 UTC
dbus-broker-14-1.fc27 has been pushed to the Fedora 27 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-2018-69fe428f56

Comment 7 Fedora Update System 2018-07-04 18:22:27 UTC
dbus-broker-14-1.fc28 has been pushed to the Fedora 28 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-2018-d278b029e6

Comment 8 Fedora Update System 2018-08-09 11:38:22 UTC
dbus-broker-15-2.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-860e8ae373

Comment 9 Fedora Update System 2018-08-09 11:38:28 UTC
dbus-broker-15-2.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-0d44ddd748

Comment 10 Fedora Update System 2018-08-09 17:11:55 UTC
dbus-broker-15-2.fc27 has been pushed to the Fedora 27 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-2018-860e8ae373

Comment 11 Fedora Update System 2018-08-09 19:02:30 UTC
dbus-broker-15-2.fc28 has been pushed to the Fedora 28 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-2018-0d44ddd748

Comment 12 Fedora Update System 2018-08-14 21:09:43 UTC
dbus-broker-15-2.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.

Comment 13 Fedora Update System 2018-08-30 03:51:41 UTC
dbus-broker-15-2.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.


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