systemd logs filled with mount unit entries if healtcheck is enabled #679
Comments
|
👍 |
|
WIth "With debug enabled" you mean both The logs you're describing (
The obvious answer would be; don't enable debug. It's assumed to be verbose and intended for debugging purposes (not usually enabled when running in production, unless you're debugging a problem). Perhaps systemd has more granular controls to enable/disable certain type of debugging messages (https://freedesktop.org/wiki/Software/systemd/Debugging/), but I haven't dug deep on finding if that's possible I'll close this issue, because this doesn't seem to be a bug, but feel free to continue the conversation |
|
I meant debug of dockerd only to figure out what is triggering this message. systemd debugging was not enabled. |
|
What version of docker are you running and on what distro? (could you post the full output of |
|
|
That looks like a non-official package; did you build that yourself, or where did you get it from? |
|
It's a build provided by my distribution of choice "PLD Linux" but I guess that's kind of a blocker so let's forget about it and focus on officially provided docker build inside Ubuntu 19.04 (note that docker is taken from 18.10 as 19.04 does not have docker-ce yet, hopefully it's not a big issue): Minimal version: '2.1'
services:
test:
image: ubuntu:18.04
healthcheck:
test: ["CMD", "/bin/true"]
interval: 5s
command: ["/bin/sh", "-c", "cat < /dev/zero > /dev/null"]Outcome in journalctl: |
|
I see the same log entries (in /var/log/daemon.log), but two every minute, and I have no healthcheck script (that I know of): This is on Debian Buster, docker from the docker repository. I would also like to know if there is a way to mute these messages! Please let me know if I should open a new issue. |
|
Same problem for me, if this can help (as some parts are different) : 6 containers are running and all have health check enabled, using |
|
This is some systemd stuff. From my limited knowledge, systemd watches for all mounts in the system and treats every one as a "unit". Why it prints success, I have no idea :( |
|
Looks like healthcheck execution results in a temporary mount (always different directory, mounted for short enough period that I could never spot it in "mount" output). Any idea where this mount is coming from? I've tried to look at containerd code but gave up. On a daily basis I'm running about 4 containers in my dev env, all having different forms of healthcheck and this log thing is quite a pain. |
|
This is a real pain. I have ~10 entries per minute just about this annoying systemd mount: Succeed crap. |
|
|
Hopefully docker will be updated to address this issue at some point. In the mean time I have added a filter for syslogd that mutes these mesages. This is on Debian Buster, but probably can be adapted to other environments. I created a new file With this, after a |
|
Today I've tried to catch exact mount parameters from /proc/self/mountinfo and found the following: Can anyone from docker team explain what is the purpose of this mount exactly? |
|
I also came across that problem. When running lots of Kubernetes pods with readyness/liveness probes using docker exec, these mounts are spamming the systemd init process. Whenever I use docker exec from the command line, it mounts the container state as @jpalus posted above. Systemd uses libmount to scan all existing mount points when the mount() system call from Docker arrives. When running 10 liveness/readiness probes per seconds on a node with >40 mount points systemd is going crazy - in addition to that it spams the journald as mentioned in the original post. |
|
Same problem here, journal is getting flooded with these messages on Fedora 30 |
|
How/why is this closed? It certainly doesn't seem resolved. Is there any workaround anyone has found? |
|
could be related to containerd/containerd#3711 but not sure if there's much that can be done about systemd spamming the logs |
|
containerd/containerd#3711 is merged, I have the latest containerd on this machine (containerd containerd.io 1.2.13 7ad184331fa3e55e52b890ea95e65ba581ae3429) and I still see those mount messages in syslog. Also each time it happens i see a spike in CPU. So definitely this issue is present and should not be marked as closed. |
|
Same thing on my side with Kubernetes, lot of these logs on master and nodes. |
|
I also have the same problem. This issue should not be closed - or information should be provided how to solve it. |
|
same here, the spam is unbearable |
|
So, did someone open a ticket in the systemd issue tracker? #679 (comment) |
|
I was able to fix this issue by setting cgroupdriver=systemd in Docker configuration. |
|
@perkooo Are you sure this fixes the |
|
@elandorr The only thing that is a fact is that journald log rotating is not pre configured by the respective Debian developers shipping the programs that log (and where doing so to daemon dedicated /var/log/.log files by Debian developers before they choose to do it otherwise when they switch to a systemd service file instead of a sysvinit script). One could argue that they now direct their log messages to the "system log" thus there is only one log file left to rotate. And I insist. The sysvinit scripts that Debian shipped were made by Debian developers and were only writing |
This comment was marked as abuse.
This comment was marked as abuse.
This comment was marked as off-topic.
This comment was marked as off-topic.
This comment was marked as abuse.
This comment was marked as abuse.
This comment was marked as abuse.
This comment was marked as abuse.
|
Hi all, this issue tracks a complex interaction between system software. Unfortunately, there has not been any productive discussion for some time, and this has mostly devolved into personal attacks. I am going to refrain from re-opening this issue for now, as currently this is by design/the architecture of Application Containers -- reconstructing mounts on each exec (where It is unfortunate that this interacts poorly with systemd, and there is work up and down the ecosystem by both the systemd and Application Container/OCI folks to try and make this better. However, because discussion here has not been fruitful for years, I think this isn't the best place to discuss/track that work for now. If there is more to do on the Docker/high-level container runtime side, we can always re-open this issue or create a new tracking issue ( |
|
opencontainers/runc#3599 was recently merged in runc, which should significantly improve this situation as the runc-driven mounts in question will be isolated to a separate mount namespace, and systemd will not log. Please refrain from off-topic remarks or personal attacks in this issue going forward. |
|
Been following this for quit some time and that is great to hear, thanks @corhere ! With the release of Debian 12 last month which is now using systemd-journald instead of rsyslog there is no workaround using filters anymore. Funny enough systemd-journald implemented filters in version 253 but Debian is using version 252. e.g. #679 (comment) this does not work anymore if you use Debian 12. |
|
@kub3let you can silence the mount messages from docker by adding This will only silence the mount messages from docker. Note that in Debian you can still log to rsyslog even with journald. Journald can act as a proxy to send messages to rsyslog without keeping a journal (ie journald storage). Just think of journald as a buffer. The systemd logfilter would have to be set on the run-docker- mount unit either way as those mount messages that systemd generates when the docker healthcheck does create mounts in the host namespace (or better to say was doing before the fix mentioned above) are logged under this mount unit, not the docker service. So having systemd v253 in bookworm would only allow to hide these messages another way. These are only workarounds until the above runc fix hits the stable docker-ce. But they help mitigate the issue until then. |
You can use a proper rsyslog filter on Debian 12 just fine. From what I gathered, they don't preinstall it by default anymore, as those who have to deal with logs will install rsyslog/ng/whatever on their own, and the rest never knew/cared. (You can even find threads of 'professional' admins asking why their docker storage blew up; seems a large chunk really doesn't care about details until snafu.) This change fixes the odd waste of resources on 11, where it duplicates data for no reason. (If you never edited configs, you had the same forwarded and in journald.) Wish they'd gone the other way around, but Debian drank the kool-aid, so it makes sense from their pov. A change in the other direction would wreak havoc downstream, while this one does nothing other than forcing admins to install yet another package. There's also syslog-ng, if you feel like you have to have something newer. But rsyslog is likely 'just right' for most needs, and has physical books that still apply. (technically ng is older, but it's the most 'modern' looking) |
|
Hi! |
|
@jenshenk the mount log messages are being emitted by systemd - pid 1 |
|
Thanks so much for the hint, saved me a lot of time and led me to this comment: #679 (comment) ... after tweaking it a bit (for me the spamming message was was .mount: Deactivated successfully) the syslog is muuuuch cleaner now. |
|
I see this has been open since a while, I also see this with the latest version of everything. Note that for me (using microk8s) I have |
|
The root issue is fixed in runc: a PR moving these mounts to somewhere systemd does not log them (opencontainers/runc#3599), and then a successor removing the mounts entirely (opencontainers/runc#3931) were accepted. runc 1.2 is eminent, and will contain one of these fixes (it's still a point of discussion if the second PR should be reverted or if it needs to be evolved as in opencontainers/runc#3987), as you can see at opencontainers/runc#3963. Once runc 1.2 hits GA, a release of containerd and Docker CE that bundle it will follow. Please refrain from adding noise to the issues I linked; we understand that this is a pain point for many (and there are other concerns here like security/performance/resource contention to be balanced), and additional "me too" will just be noise. |
this works for me with microk8s |
|
https://github.com/opencontainers/runc/milestone/13 |
|
I don't know! I also have been sitting staring at my terminal, and waiting, and waiting, and nothing happened! Asked a colleague to sit next to me, perhaps 2 people sit and wait made it go faster, but nope. |
Thank you @prahal - this worked and finally silenced these log messages (Debian 12) |
It looks like we're not alone. I'm trying to reduce some noise setting up a loggin stack with loki.
would the folder/file in etc be: or similar? ---edit--- |
|
I suspect this was made worse in the last year or so due to mitigations in runc for GHSA-gxmr-w5mj-v8hh. Starting with runc v1.1.15 this is no longer using a mount, though there is some extra memory overhead during container/healthcheck setup. |
These are not user space messages but kernel ones, even though they are related to the network interfaces that docker brings up. Kernel logging kernel level messages in the kernel log is kind of the point of kernel logs ... but you may ask on systemd forums or such if someone knows a mean to remove them from the journald logs (or ask on rsyslog ML or such if you are using rsyslog). These are not bugs. They do not slow down the computer, are not by the hundreds, etc. Definitely don't open a bug for such messages that are definitely not bugs. Ask on discussion forums or such, issue tracker are not the place to ask for people to teach one how to use a tool or if a question makes sense. |
and others
I've got a simple container running with healthcheck script executed every 5s. It's's working fine but each healtcheck script execution results in 4 log entries:
With debug enabled that's:
Therefore system logs are literally filled with mount unit entries. Is this something to be expected by default? What would be the best way to get rid of it?
The text was updated successfully, but these errors were encountered: