First, add runc --debug exec test cases, very similar to those in
debug.bats but for runc exec (rather than runc run). Do not include json
tests as it is already tested in debug.bats.
Second, add logrus debug to late stages of runc init, and amend the
integration tests to check for those messages. This serves two purposes:
- demonstrate that runc init can be amended with debug logrus which is
properly forwarded to and logged by the parent runc create/run/exec;
- improve the chances to catch the race fixed by the previous commit.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Sometimes debug.bats test cases are failing like this:
> not ok 27 global --debug to --log --log-format 'json'
> # (in test file tests/integration/debug.bats, line 77)
> # `[[ "${output}" == *"child process in init()"* ]]' failed
It happens more when writing to disk.
This issue is caused by the fact that runc spawns log forwarding goroutine
(ForwardLogs) but does not wait for it to finish, resulting in missing
debug lines from nsexec.
ForwardLogs itself, though, never finishes, because it reads from a
reading side of a pipe which writing side is not closed. This is
especially true in case of runc create, which spawns runc init and
exits; meanwhile runc init waits on exec fifo for arbitrarily long
time before doing execve.
So, to fix the failure described above, we need to:
1. Make runc create/run/exec wait for ForwardLogs to finish;
2. Make runc init close its log pipe file descriptor (i.e.
the one which value is passed in _LIBCONTAINER_LOGPIPE
environment variable).
This is exactly what this commit does:
1. Amend ForwardLogs to return a channel, and wait for it in start().
2. In runc init, save the log fd and close it as late as possible.
PS I have to admit I still do not understand why an explicit close of
log pipe fd is required in e.g. (*linuxSetnsInit).Init, right before
the execve which (thanks to CLOEXEC) closes the fd anyway.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
- add check, checkWait, and finish helpers;
- move test cleanup to runLogForwarding;
- introduce and use log struct.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
I have noticed that ConfigureLogs do not return an error in case logging
was already configured -- instead it just warns about it. So I went
ahead and changed the warning to the actual error...
... only to discover I broke things badly, because in case of runc init
logging is configured twice. The fix is to not configure logging in case
we are init.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Error handling is slightly cleaner this way.
While at it, do minor refactoring and fix error logging
in processEntry.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
1. Remove redundant "echo $output" from the first test case, as "runc"
helper function already logs the output.
2. Show the contents of log.out to stderr, so it case of error we can
see what is going on.
3. Remove the check that `log.out` file exists. This check is redundant,
since right after it we do `cat log.out` and check its exit code.
4. Factor out common checks into check_debug.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
As pointed out to in [1], seccomp.IsEnabled does some runtime checks,
while here (when printing libseccomp version) we should merely print
the version number of libseccomp, if compiled in.
Change the code to check if the version is non-zero (as seccomp.Version
returns 0, 0, 0 in case seccomp is not compiled in.
[1] https://github.com/opencontainers/runc/pull/2866
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
Sometimes the test fails without any clear diagnostics:
> not ok 16 checkpoint --lazy-pages and restore
> (in test file tests/integration/checkpoint.bats, line 191)
> `[ "$out" = "0000000 000000 0000001" ]' failed
> ...
> criu failed: type NOTIFY errno 3\nlog file: work-dir/dump.log
We look for and print errors via grep, but in the above case
there are nothing that is denoted error in the log.
So, let's show the damn log in its entirely (note it is only shown
if test fails).
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
if bfq is not loaded, then io.bfq.weight is not available. io.weight
should always be available and is the next best equivalent thing.
Signed-off-by: Daniel Dao <dqminh89@gmail.com>
Sometimes github gives up 5xx errors, for example:
> panic: getImages error exit status 1 (output: curl: (22) The requested URL returned error: 502
> Failed to get https://github.com/docker-library/busybox/raw/dist-i386/stable/glibc/busybox.tar.xz
This is unfortunate but temporary, and adding --retry should handle
at least some cases, improving CI stability.
Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
bfq weight controller (i.e. io.bfq.weight if present) is still using the
same bfq weight scheme (i.e 1->1000, see [1].) Unfortunately the
documentation for this was wrong, and only fixed recently [2].
Therefore, if we map blkio weight to io.bfq.weight, there's no need to
do any conversion. Otherwise, we will try to write invalid value which
results in error such as:
```
time="2021-02-03T14:55:30Z" level=error msg="container_linux.go:367: starting container process caused: process_linux.go:495: container init caused: process_linux.go:458: setting cgroup config for procHooks process caused: failed to write \"7475\": write /sys/fs/cgroup/runc-cgroups-integration-test/test-cgroup/io.bfq.weight: numerical result out of range"
```
[1] https://github.com/torvalds/linux/blob/master/Documentation/block/bfq-iosched.rst
[2] https://github.com/torvalds/linux/commit/65752aef0a407e1ef17ec78a7fc31ba4e0b360f9
Signed-off-by: Daniel Dao <dqminh89@gmail.com>
Sebastiaan van Stijn