Bug 1639482 - journalctl reports a totally useless ' The start-up result is RESULT.' and "Failed with result 'exit-code'.
Summary: journalctl reports a totally useless ' The start-up result is RESULT.' and "F...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-10-15 20:23 UTC by Valdis Kletnieks
Modified: 2018-11-04 22:08 UTC (History)
6 users (show)

Fixed In Version: systemd-239-6.git9f3aed1.fc29 systemd-238-10.git438ac26.fc28
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-11-01 15:06:46 UTC
Type: Bug


Attachments (Terms of Use)

Description Valdis Kletnieks 2018-10-15 20:23:40 UTC
Description of problem:
I run 'journalctl -xb' while trying to troubleshoot a boot-time issue. And *every single thing* that gets started reports:

-- The start-up result is RESULT.

15:43:09 [~] journalctl -xb | grep 'start-up result' | wc -l
196
15:43:21 [~] journalctl -xb | grep 'start-up result' | grep -v RESULT | wc -l
0

And I know that at least one unit failed (due to not having a kernel module):

15:48:20 0 [~]1 journalctl -xb -u vboxdrv.service
-- Logs begin at Thu 2014-05-29 11:18:59 EDT, end at Mon 2018-10-15 15:48:36 EDT. --
Oct 15 15:31:10 turing-police.cc.vt.edu systemd[1]: Starting VirtualBox Linux kernel module...
-- Subject: Unit vboxdrv.service has begun start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit vboxdrv.service has begun starting up.
Oct 15 15:31:10 turing-police.cc.vt.edu vboxdrv.sh[1212]: vboxdrv.sh: Starting VirtualBox services.
Oct 15 15:31:10 turing-police.cc.vt.edu vboxdrv.sh[1285]: Starting VirtualBox services.
Oct 15 15:31:11 turing-police.cc.vt.edu vboxdrv.sh[1212]: vboxdrv.sh: failed: modprobe vboxnetadp failed. Please use 'dmesg' to find out why.
Oct 15 15:31:11 turing-police.cc.vt.edu systemd[1]: vboxdrv.service: Control process exited, code=exited status=1
Oct 15 15:31:11 turing-police.cc.vt.edu systemd[1]: vboxdrv.service: Failed with result 'exit-code'.
Oct 15 15:31:11 turing-police.cc.vt.edu systemd[1]: Failed to start VirtualBox Linux kernel module.
-- Subject: Unit vboxdrv.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit vboxdrv.service has failed.
-- 
-- The result is RESULT.

And it *STILL* says 'RESULT'. If it's not going to print useful info, don't bother printing it at all.

Oh, I take that back:

15:50:55 [~] journalctl -xb | grep result | sort | uniq -c
      1 -- The result is RESULT.
    197 -- The start-up result is RESULT.
      1 Oct 15 15:31:10 turing-police.cc.vt.edu systemd[1]: dbxtool.service: Failed with result 'exit-code'.
      1 Oct 15 15:31:11 turing-police.cc.vt.edu systemd[1]: vboxdrv.service: Failed with result 'exit-code'.
      1 Oct 15 15:31:34 turing-police.cc.vt.edu systemd[1552]: at-spi-dbus-bus.service: Failed with result 'exit-code'.

In one case, it doesn't put 'start-up' in the output.

While we're at it - "Failed with result 'exit-code'."  That's another useless message - I then have to find a *different* line of output in order to actually see what the error was. It presumably knows the exit code, so "Failed with result 'exit-code=97'." would be easy enough to do.  Not so bad if you're already looking at that unit's output - but makes life a lot harder if you're automating log scanning....

Version-Release number of selected component (if applicable):
systemd-239-5.fc30.x86_64

How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 1 Zbigniew Jędrzejewski-Szmek 2018-10-15 20:56:29 UTC
Re "RESULT": https://github.com/systemd/systemd/pull/10413

Re "Failed with result 'exit-code'.": the details about what failed are logged earlier. E.g. here I have:
Sep 23 21:52:16 krowka systemd[1]: dkms.service: Main process exited, code=exited, status=127/n/a
Sep 23 21:52:16 krowka systemd[1]: dkms.service: Failed with result 'exit-code'.
Sep 23 21:52:16 krowka systemd[1]: Failed to start Builds and install new kernel modules through DKMS.

The details about the failing binary are logged first, and the details about the failure are not propagated to the outer code. This is on purpose — higher levels don't care about the low-level details. 'exit-code' means that the service failed because some binary returned an error, as opposed to e.g. it being terminated by a signal.

Comment 2 Fedora Update System 2018-10-29 01:52:09 UTC
systemd-239-6.git9f3aed1.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2018-c402eea18b

Comment 3 Fedora Update System 2018-10-29 14:58:36 UTC
systemd-238-10.git438ac26.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-24bd6c9d4a

Comment 4 Fedora Update System 2018-10-31 17:30:40 UTC
systemd-238-10.git438ac26.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-24bd6c9d4a

Comment 5 Fedora Update System 2018-10-31 18:50:48 UTC
systemd-239-6.git9f3aed1.fc29 has been pushed to the Fedora 29 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-c402eea18b

Comment 6 Fedora Update System 2018-11-01 15:06:46 UTC
systemd-239-6.git9f3aed1.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.

Comment 7 Fedora Update System 2018-11-04 22:08:35 UTC
systemd-238-10.git438ac26.fc28 has been pushed to the Fedora 28 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.