[DNM] runc init log refactor #3114
Closed
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
kolyshkin
force-pushed
the
init-log-refactor
branch
2 times, most recently
from
485f194 to
b1bc762
Compare
This was referenced Jul 29, 2021
kolyshkin
force-pushed
the
init-log-refactor
branch
3 times, most recently
from
44487fb to
ecddba7
Compare
This function is somewhat strange and I always wanted to remove it, as it tries to satisfy both init.go and main.go, which have somewhat different needs. It is more straightforward and readable to configure logrus directly. Signed-off-by: Kir Kolyshkin <[email protected]>
Previous commits removed all its users -- the only one left is package's own unit tests. Modify those unit tests to configure logrus directly, and remove ConfigureLogging for good. The world is better without it. Signed-off-by: Kir Kolyshkin <[email protected]>
When playing with the log forwarder, I broke it, but all the units tests were still passing. This happened because test cases were merely looking for a work like "kitten" in the log output, which was also there as a part of an error message produced by log forwarder. Make the test a bit more robust by - looking for a complete log message, not just part of it; - also checking that log file does not contain errors. Signed-off-by: Kir Kolyshkin <[email protected]>
There's no need to call logrus.ParseLevel as logrus.Level already implements encoding.TextUnmarshaler interface. Signed-off-by: Kir Kolyshkin <[email protected]>
Commit 9f3d753 enabled logrus to show information about log caller, if --debug is set. It is helpful in many scenarios, but does not work very well when we are debugging runc init, for example: # runc --debug run -d xx4557 DEBU[0000]libcontainer/logs/logs.go:45 github.com/opencontainers/runc/libcontainer/logs.processEntry() nsexec[279687]: logging set up DEBU[0000]libcontainer/logs/logs.go:45 github.com/opencontainers/runc/libcontainer/logs.processEntry() nsexec[279687]: logging set up DEBU[0000]libcontainer/logs/logs.go:45 github.com/opencontainers/runc/libcontainer/logs.processEntry() nsexec[279687]: => nsexec container setup DEBU[0000]libcontainer/logs/logs.go:45 github.com/opencontainers/runc/libcontainer/logs.processEntry() nsexec[279687]: update /proc/self/oom_score_adj to '30' As we're merely forwarding the logs here, printing out filename:line and function is useless and clutters the logs a log. To fix, create and use a copy of the standard logger with caller info turned off. With this in place, nsexec logs are sane again: # runc --debug --log-format=text run -d xe34 DEBU[0000] nsexec[293595]: logging set up DEBU[0000] nsexec[293595]: logging set up DEBU[0000] nsexec[293595]: => nsexec container setup DEBU[0000] nsexec[293595]: update /proc/self/oom_score_adj to '30' This patch also changes Logf to Log in processEntry, as this is what it should be. Signed-off-by: Kir Kolyshkin <[email protected]>
Signed-off-by: Kir Kolyshkin <[email protected]>
1. Make sure we close all file descriptors at the end of the test. 2. Make sure we close child fds after the start. 3. Use newPipe for logs as well, for simplicity and uniformity. Signed-off-by: Kir Kolyshkin <[email protected]>
The test was not working since at least commit 64bb59f renamed pid to stage2_pid (or maybe even earlier), so the pid was never received (i.e. pid.Pid was 0). The problem was not caught because os.FindProcess never return an error on Unix. Factor out and fix pid decode function: - use DisallowUnknownInput to get error if JSON will be changed; - check pids to make sure they are valid - and use unix.Wait4 to reap zombies. Signed-off-by: Kir Kolyshkin <[email protected]>
Instead of reading a single message, do read all the logs from the init, and use DisallowUnknownFields for stricter checking. While at it, use reapChildren to reap zombies (and add an extra check). Signed-off-by: Kir Kolyshkin <[email protected]>
Signed-off-by: Kir Kolyshkin <[email protected]>
newProcess do not need those extra arguments, they can be handled in the caller. Signed-off-by: Kir Kolyshkin <[email protected]>
Instead of passing _LIBCONTAINER_LOGLEVEL as a string (like "debug" or "info"), use a numeric value. Also, simplify the init log level passing code -- since we actually use the same level as the runc binary, just get it from logrus. This is a preparation for the next commit. Signed-off-by: Kir Kolyshkin <[email protected]>
This makes it possible to use bail() even if logging is not set up (yet), so we don't have to think whether it's OK to use it or not. In addition, this might help some unit tests that do not set log forwarding. Signed-off-by: Kir Kolyshkin <[email protected]>
The code already parses an environment variable into an integer twice, and we're about to add a third one. Factor it out to getenv_int(). Signed-off-by: Kir Kolyshkin <[email protected]>
Currently, if the log level is not set to e.g. "debug", runc init sends some debug logs to the parent, which parses and discards it. It is better to not send those in the first place. Signed-off-by: Kir Kolyshkin <[email protected]>
Commit 9f3d753 enabled logrus to show information about log caller, if --debug is set. The problem is, the file name and in many cases the function name have a long prefix of github.com/opencontainers/runc (this is with -trimpath, and without it it's worse). Add a function to trim the prefix. Note all this happens only when --debug is given. Signed-off-by: Kir Kolyshkin <[email protected]>
kolyshkin
force-pushed
the
init-log-refactor
branch
from
ecddba7 to
0e98915
Compare
Contributor
Author
|
OK, I guess it's time to dismantle this into a few more digestible pieces.
|
This was referenced Aug 12, 2021
Merged
Contributor
Author
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
This PR is mostly about runc init log refactoring. Makes the code more readable, improves its tests, fixes some issues.
Remove
logs.ConfigureLoggingwhose existence always bugged me.Improve libct/logs and its tests.
Fix/improve libct/nsenter tests.
Make nsexec aware of the log level (i.e. do not emit logs that are to be discarded).
Small improvement (not related to init logs)
Update: split into a few smaller PRS: