Bug 1307018 - While --log-target=null silences console output, --log-target=journal does not
While --log-target=null silences console output, --log-target=journal does not
Status: CLOSED CURRENTRELEASE
Product: Fedora
Classification: Fedora
Component: systemd (Show other bugs)
23
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: systemd-maint
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2016-02-12 08:10 EST by Jan Pazdziora
Modified: 2016-11-25 08:44 EST (History)
8 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-11-25 08:44:27 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Jan Pazdziora 2016-02-12 08:10:21 EST
Description of problem:

In an attempt to minimize output generated by systemd in docker container but still have logs/progress preserved, I use --log-target=journal. However, warnings still seem to be shown on docker run output (= console).

Checking with --log-target=null shows that those outputs respect --log-target (up to a point, see bug 1307014), but it seems to behave as if journal meant journal+console.

Version-Release number of selected component (if applicable):

$ docker exec systemd rpm -q systemd
systemd-222-10.fc23.x86_64

How reproducible:

Deterministic.

Steps to Reproduce:
1. $ docker run --name systemd -ti -v /run -v /sys/fs/cgroup:/sys/fs/cgroup:ro -e container=docker fedora /usr/sbin/init --show-status=false --log-target=null
2. Observe no output on console (except for one Running in a container, ignoring fstab device entry message).
3. In another terminal $ docker exec systemd journalctl -b
4. Observe

Feb 12 13:02:49 4c49df728bca systemd-journal[23]: Runtime journal is using 8.0M (max allowed 1.1G, trying to leave 1.7G free of 1.9G available → current limit 232.5M).
Feb 12 13:02:50 4c49df728bca systemd-journal[23]: Permanent journal is using 8.0M (max allowed 995.1M, trying to leave 1.4G free of 8.9G available → current limit 995.1M).
Feb 12 13:02:50 4c49df728bca systemd-journal[23]: Time spent on flushing to /var is 112.152ms for 2 entries.
Feb 12 13:02:50 4c49df728bca systemd-journal[23]: Journal started
Feb 12 13:02:50 4c49df728bca mount[22]: mount: permission denied
Feb 12 13:02:50 4c49df728bca mount[35]: mount: permission denied

5. $ docker rm -f systemd
6. $ docker run --name systemd -ti -v /run -v /sys/fs/cgroup:/sys/fs/cgroup:ro -e container=docker fedora /usr/sbin/init --show-status=false --log-target=journal
7. In another container: $ docker exec systemd journalctl -b

Actual results:

On console (docker run output):

systemd 222 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ -LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
Detected virtualization docker.
Detected architecture x86-64.
Running with unpopulated /etc.
Set hostname to <e6aaa1c88a23>.
Initializing machine ID from random generator.
Populated /etc with preset unit settings.
Running in a container, ignoring fstab device entry for /dev/disk/by-uuid/06116abf-da19-442c-81f9-543aacaf8f1b.
dev-hugepages.mount: Cannot add dependency job, ignoring: Unit dev-hugepages.mount is masked.
systemd-remount-fs.service: Cannot add dependency job, ignoring: Unit systemd-remount-fs.service is masked.
sys-fs-fuse-connections.mount: Cannot add dependency job, ignoring: Unit sys-fs-fuse-connections.mount is masked.
systemd-logind.service: Cannot add dependency job, ignoring: Unit systemd-logind.service is masked.
getty.target: Cannot add dependency job, ignoring: Unit getty.target is masked.
tmp.mount: Directory /tmp to mount over is not empty, mounting anyway.
tmp.mount: Mount process exited, code=exited status=32
systemd-user-sessions.service: Job systemd-user-sessions.service/start failed with result 'dependency'.
dbus.service: Job dbus.service/start failed with result 'dependency'.
multi-user.target: Job multi-user.target/start failed with result 'dependency'.
machines.target: Job machines.target/start failed with result 'dependency'.
basic.target: Job basic.target/start failed with result 'dependency'.
tmp.mount: Unit entered failed state.

In journal:

-- Logs begin at Fri 2016-02-12 13:04:48 UTC, end at Fri 2016-02-12 13:04:50 UTC. --
Feb 12 13:04:48 e6aaa1c88a23 systemd-journal[21]: Runtime journal is using 8.0M (max allowed 1.1G, trying to leave 1.7G free of 1.9G available → current limit 224.3M).
Feb 12 13:04:49 e6aaa1c88a23 systemd-journal[21]: Permanent journal is using 8.0M (max allowed 995.1M, trying to leave 1.4G free of 8.9G available → current limit 995.1M).
Feb 12 13:04:49 e6aaa1c88a23 systemd-journal[21]: Time spent on flushing to /var is 358.888ms for 2 entries.
Feb 12 13:04:49 e6aaa1c88a23 systemd-journal[21]: Journal started
Feb 12 13:04:49 e6aaa1c88a23 mount[22]: mount: permission denied
Feb 12 13:04:49 e6aaa1c88a23 systemd[1]: Starting Flush Journal to Persistent Storage...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Flush Journal to Persistent Storage.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting Create Volatile Files and Directories...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Create Volatile Files and Directories.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Update UTMP about System Boot/Shutdown.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting Update UTMP about System Runlevel Changes...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Reached target System Initialization.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting System Initialization.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Daily Cleanup of Temporary Directories.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting Daily Cleanup of Temporary Directories.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Listening on D-Bus System Message Bus Socket.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting D-Bus System Message Bus Socket.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: sys-fs-fuse-connections.mount: Cannot add dependency job, ignoring: Unit sys-fs-fuse-connections.mount is masked.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Starting Cleanup of Temporary Directories...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Mounting Temporary Directory...
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Update UTMP about System Runlevel Changes.
Feb 12 13:04:50 e6aaa1c88a23 mount[34]: mount: permission denied
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: tmp.mount: Mount process exited, code=exited status=32
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Failed to mount Temporary Directory.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Dependency failed for Basic System.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Dependency failed for dnf makecache.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: dnf-makecache.service: Job dnf-makecache.service/start failed with result 'dependency'.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: basic.target: Job basic.target/start failed with result 'dependency'.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: tmp.mount: Unit entered failed state.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Started Cleanup of Temporary Directories.
Feb 12 13:04:50 e6aaa1c88a23 systemd[1]: Startup finished in 1.796s.

Expected results:

No output from docker run. All the output from the console in journal.

Definitely not

dnf-makecache.service: Job dnf-makecache.service/start failed with result 'dependency'.

both on console and in journal.

Additional info:
Comment 1 Fedora End Of Life 2016-11-24 10:31:59 EST
This message is a reminder that Fedora 23 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 23. 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 '23'.

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 23 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 2 Jan Pazdziora 2016-11-25 08:44:27 EST
I don't see the message printed on Fedora 24 anymore, with neither fedora:23, nor fedora:24 images. Not sure if something got fixed or I'm just not hitting the same situation anymore.

It sure would have been great if someone from the systemd maintainers at least commented on the bugzilla.

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