for-linux icon indicating copy to clipboard operation
for-linux copied to clipboard

Docker daemon logging to systemd doesn't honor log level

Open HontoNoRoger opened this issue 8 years ago • 7 comments

  • [x] This is a bug report
  • [ ] This is a feature request
  • [x] I searched existing issues before opening this one

I don't know if this is the right place to write that bug report, since you're using logrus for daemon logging. But I guess it's supported by logrus.

Expected behavior

The output of journalctl -u docker.service should highlight log messages with level warning and higher. also -p flag should filter for the proper log levels.

Actual behavior

All docker daemon log messages are being logged with priority info instead of the actual log levels which are in the Docker daemon log message field.

Steps to reproduce the behavior

  1. Install Docker on Ubuntu 16.04
  2. generate an error message for the Docker daemon, e.g. with docker run fsdufrhfhu (an image which can't be found)
  3. use journalctl -u docker.service to see plain messages, use journalctl -u docker.service -p err or other higher priority levels (>= warning). Output shows -- No entries -- since the log messages don't get the priority level of the log message level field.

Output of docker version:

Client:
 Version:      17.09.0-ce
 API version:  1.32
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:42:18 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.09.0-ce
 API version:  1.32 (minimum version 1.12)
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:40:56 2017
 OS/Arch:      linux/amd64
 Experimental: false

Output of docker info:

Containers: 8
 Running: 1
 Paused: 0
 Stopped: 7
Images: 71
Server Version: 17.09.0-ce
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 431
 Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 06b9cb35161009dcb7123345749fef02f7cea8e0
runc version: 3f2f8b84a77f73d38244dd690525642a72156c64
init version: 949e6fa
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.4.0-96-generic
Operating System: Ubuntu 16.04.3 LTS
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 15.65GiB
Name: rechenknecht
ID: 47ZH:DV7R:K46H:ZAGA:6OTS:TAVW:U4XG:WETG:EHVX:Y3SH:AZDR:FPYU
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: No swap limit support

HontoNoRoger avatar Oct 12 '17 08:10 HontoNoRoger

Docker isn't logging to journald, it's logging to stdout/stderr. I don't think I would consider this a bug.

cpuguy83 avatar Oct 12 '17 13:10 cpuguy83

I'm talking about the Docker daemon's logging behavior of a standard installation on Ubuntu 16.04 (and up). The Docker daemon logs (not the container logs) will be sent to the platform specific subsystem for logging. The subsystem in question here is systemd, which doesn't really parse (or honor) the log severity specified in the log message of the Docker daemon. See https://docs.docker.com/engine/admin/#read-the-logs

I would consider this a bug, since the severity information is there but won't be honored in a default installation case. Thus filtering on severity level won't work out of the box for people using journalctl. Also, for people forwarding the syslog/journalctl messages to a centralized system, e.g. an ELK stack it's quite a hassle to have those messages appear as "info" even if the level tag in the message says differently. This might result in important logging events won't be seen at all.

HontoNoRoger avatar Oct 12 '17 15:10 HontoNoRoger

Yes, dockerd sends everything to stdout/stderr itself (for the daemon logs). This is consumed by systemd/journald. Maybe I'm not sure how this should be output for journald to parse severity.

cpuguy83 avatar Oct 12 '17 15:10 cpuguy83

Ok, apparently systemd looks at the beginning of the message to see if it is prefixed with a priority like so <5>

cpuguy83 avatar Oct 16 '17 21:10 cpuguy83

It's a bit tricky because moby/moby doesn't want to make any assumptions about the thing that started it. It also doesn't really feel right to put this in the daemon config. Will have to think about what we can do to handle severity of the messages, I agree it would be nice.

cpuguy83 avatar Oct 16 '17 21:10 cpuguy83

Any news regarding this @HontoNoRoger @cpuguy83 ?

So at the moment, it is still not possible to honor the docker daemon log-level while using systemd as a logging subsystem?

geez avatar Apr 04 '18 15:04 geez

This needs someone to work on it. I think having a config to enable journald severity support would work well.

cpuguy83 avatar Apr 04 '18 15:04 cpuguy83