Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

update containerd binary to v1.6.1 #42942

Merged
merged 1 commit into from Mar 12, 2022

Conversation

thaJeztah
Copy link
Member

- What I did

- How I did it

- How to verify it

- Description for the changelog

- A picture of a cute animal (not mandatory but encouraged)

@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.0 update containerd binary to v1.6.0-beta.1 Oct 25, 2021
@thaJeztah thaJeztah force-pushed the containerd_binary_1.6 branch 3 times, most recently from 53a9eea to 8958328 Compare October 27, 2021 10:34
@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.1 update containerd binary to v1.6.0-beta.2 Nov 16, 2021
Dockerfile.windows Outdated Show resolved Hide resolved
@thaJeztah thaJeztah force-pushed the containerd_binary_1.6 branch 4 times, most recently from e7bdede to 038ae6a Compare November 22, 2021 11:54
@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.2 update containerd binary to v1.6.0-beta.3 Nov 22, 2021
@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.3 update containerd binary to v1.6.0-beta.4 Dec 22, 2021
@thaJeztah
Copy link
Member Author

Argh.. I never understand PowerShell;

https://github.com/containerd/containerd/releases/download/v${Env:CONTAINERD_VERSION}/containerd-${Env:CONTAINERD_VERSION}-windows-amd64.tar.gz :
The term 'https://github.com/containerd/containerd/releases/download/v${Env:CONTAINERD_VERSION}/containerd-${Env:CONTAINERD_VERSION}-windows-amd64.tar.gz'
is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify
that the path is correct and try again. At line:1 char:3159

Guess it's just back to concatenating stuff <flip-table />

@tianon
Copy link
Member

tianon commented Dec 22, 2021

$location='https://github.com/containerd/containerd/releases/download/v'+$Env:CONTAINERD_VERSION+'/containerd-'+$Env:CONTAINERD_VERSION+'-windows-amd64.tar.gz';

Could instead be:

$location = 'https://github.com/containerd/containerd/releases/download/v{0}/containerd-{0}-windows-amd64.tar.gz' -f $env:CONTAINERD_VERSION;

Demo:

PS C:\> $location = 'https://github.com/containerd/containerd/releases/download/v{0}/containerd-{0}-windows-amd64.tar.gz' -f $env:CONTAINERD_VERSION 
PS C:\> write-host $location
https://github.com/containerd/containerd/releases/download/v1.6.0-beta.4/containerd-1.6.0-beta.4-windows-amd64.tar.gz

@thaJeztah
Copy link
Member Author

Thanks! So I tried putting the ${Env:Foo} inside the string, which felt like a slightly more readable approach;

$location="https://github.com/containerd/containerd/releases/download/v${Env:CONTAINERD_VERSION}/containerd-${Env:CONTAINERD_VERSION}-windows-amd64.tar.gz"

Which (looking at https://docs.microsoft.com/en-us/powershell/scripting/learn/deep-dives/everything-about-string-substitutions?view=powershell-7.2) seemed like it was supported, but not sure why it then tries to execute the string.

Guess the devil is in the detail ... somewhere.

Not worth spending too much time on for now, I guess, so I just reverted it to what it was

@thaJeztah
Copy link
Member Author

Maybe it expects it to be used without Env: and I should've used the plain $VAR or ${VAR} in it, idk 😂

@thaJeztah
Copy link
Member Author

Failing tests:

  • ⚠️ TestRunContainerWithRmFlagCannotStartContainer (possible regression, but could be racy)
  • ⚠️ TestRunMutableNetworkFiles (possible regression)
  • ⚠️ TestDaemonRestartSaveContainerExitCode (possible regression)
  • ✔️ (likely flaky) TestNetworkDBIslands
  • ✔️ (likely flaky) TestNetworkDBCRUDTableEntries
  • ✔️ (likely flaky) TestJSONFileLoggerWithOpts

This test looks like a possible regression, although it was known to be racy before (see #11966)

=== RUN   TestDockerSuite/TestRunContainerWithRmFlagCannotStartContainer
    docker_cli_run_test.go:2776: Expected not to have containers 2492808e26cc

    --- FAIL: TestDockerSuite/TestRunContainerWithRmFlagCannotStartContainer (0.43s)

This could be a regression; although I can find various mentions of this test, some of which indicate it may have been racy https://github.com/moby/moby/search?p=1&q=TestRunMutableNetworkFiles&type=issues
"exit status 1" looks fishy though

=== RUN   TestDockerSuite/TestRunMutableNetworkFiles
    docker_cli_exec_test.go:389: assertion failed:
        Command:  /usr/local/cli/docker rm -fv 2492808e26cc
        ExitCode: 1
        Error:    exit status 1
        Stdout:
        Stderr:   Error response from daemon: No such container: 2492808e26cc


        Failures:
        ExitCode was 1 expected 0
        Expected no error
    --- FAIL: TestDockerSuite/TestRunMutableNetworkFiles (0.04s)

This could be a regression (don't see many mentions of that test failing, and online from a long time ago) https://github.com/moby/moby/search?q=TestDaemonRestartSaveContainerExitCode&type=issues

=== RUN   TestDockerDaemonSuite/TestDaemonRestartSaveContainerExitCode
    docker_cli_daemon_test.go:2636: assertion failed: 137 (out string) != 127 (string)
    --- FAIL: TestDockerDaemonSuite/TestDaemonRestartSaveContainerExitCode (1.46s)

Failure in TestNetworkDBIslands - known flaky: #42459

Windows 2022 / containerd (flaky test); #42739

=== RUN   TestNetworkDBCRUDTableEntries
    networkdb_test.go:310: Entry existence verification test failed for node2(1f082a212f1b)
2021/12/22 18:01:59 Closing DB instances...
--- FAIL: TestNetworkDBCRUDTableEntries (7.91s)

Windows RS5 (flaky test?) was flaky before: #36801

=== RUN   TestJSONFileLoggerWithOpts
    jsonfilelog_test.go:187: open C:\Users\ContainerAdministrator\AppData\Local\Temp\docker-logger-2690863916\container.log.1: The process cannot access the file because it is being used by another process.
--- FAIL: TestJSONFileLoggerWithOpts (0.02s)

@thaJeztah
Copy link
Member Author

New run of CI:

On amd64: this is starting to look like a regression:

=== RUN   TestDockerDaemonSuite/TestDaemonRestartSaveContainerExitCode
    docker_cli_daemon_test.go:2636: assertion failed: 137 (out string) != 127 (string)
    --- FAIL: TestDockerDaemonSuite/TestDaemonRestartSaveContainerExitCode (1.74s)

On Windows RS5: known flaky test #38521

=== RUN   TestDockerSuite/TestStartReturnCorrectExitCode
    docker_cli_start_test.go:209: assertion failed: expected an error, got nil
    --- FAIL: TestDockerSuite/TestStartReturnCorrectExitCode (9.84s)

Giving it another run

@tianon
Copy link
Member

tianon commented Jan 6, 2022

Running docker run --rm busybox toto and even docker run --rm --init busybox toto by hand with Docker 20.10 or a fresh build from master combined with https://github.com/containerd/containerd/releases/download/v1.6.0-beta.5/containerd-1.6.0-beta.5-linux-amd64.tar.gz works every time and returns 127 as expected. 😩

@thaJeztah
Copy link
Member Author

@tianon thanks for trying! So 🤔 differences in our CI situation would be;

  • it's running docker-in-docker
  • it's integration-cli, and using the docker 17.06 cli (although for these options, I can't see how that would matter)

For easier finding; this is the test that's failing;

func (s *DockerDaemonSuite) TestDaemonRestartSaveContainerExitCode(c *testing.T) {

And it looks pretty straightforward (run a container that uses a non-existing binary as command);

_, err := s.d.Cmd("run", "--name", containerName, "--init=false", "busybox", "toto")
assert.ErrorContains(c, err, "")
// Check that those values were saved on disk
out, err := s.d.Cmd("inspect", "-f", "{{.State.ExitCode}}", containerName)
out = strings.TrimSpace(out)
assert.NilError(c, err)
assert.Equal(c, out, "127")

@thaJeztah
Copy link
Member Author

oh, and of course the CI uses the frozen images, so the version of the busybox image is

moby/Dockerfile

Lines 91 to 92 in 0f1d65b

busybox:latest@sha256:95cf004f559831017cdf4628aaf1bb30133677be8702a8c5f2994629f637a209 \
busybox:glibc@sha256:1f81263701cddf6402afe9f33fca0266d9fff379e59b1748f33d3072da71ee85 \

@tianon
Copy link
Member

tianon commented Jan 6, 2022

Looks like the server is using 20.10.10-rc1 -- any idea what version of libseccomp? (Just to start ruling things out.)

Maybe we can try running that specific integration test locally to see if we can reproduce outside CI too (or making a test commit that limits CI to just that test and see if that passes 😂 🙈).

@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.4 update containerd binary to v1.6.0-beta.5 Jan 10, 2022
@thaJeztah
Copy link
Member Author

thaJeztah commented Jan 10, 2022

I'm able to reproduce the issue when running inside the dev container (make BIND_DIR=. binary shell);

docker pull busybox

docker run --name error-values --init=false busybox toto
docker: Error response from daemon: failed to create shim task: OCI runtime create failed: container_linux.go:380: starting container process caused: exec: "toto": executable file not found in $PATH: unknown.
ERRO[0004] error waiting for container: context canceled

docker inspect -f '{{.State.ExitCode}}' error-values
137

daemon logs related to the above:

DEBU[2022-01-10T11:55:43.507894777Z] Calling POST /v1.30/containers/create?name=error-values
DEBU[2022-01-10T11:55:43.509033292Z] form data: {"AttachStderr":true,"AttachStdin":false,"AttachStdout":true,"Cmd":["toto"],"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":null,"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"Init":false,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"busybox","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":false,"StdinOnce":false,"Tty":false,"User":"","Volumes":{},"WorkingDir":""}
DEBU[2022-01-10T11:55:43.530752968Z] container mounted via layerStore: &{/var/lib/docker/overlay2/826c78df23cd3bc99913e9d0f78426fe15e9b93e4c5ae683f92842a39482952c/merged 0x344f560 0x344f560}  container=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81
DEBU[2022-01-10T11:55:43.548080697Z] Calling POST /v1.30/containers/086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81/attach?stderr=1&stdout=1&stream=1
DEBU[2022-01-10T11:55:43.548626728Z] attach: stdout: begin
DEBU[2022-01-10T11:55:43.548974635Z] attach: stderr: begin
DEBU[2022-01-10T11:55:43.549582742Z] Calling POST /v1.30/containers/086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81/wait?condition=next-exit
DEBU[2022-01-10T11:55:43.550842848Z] Calling POST /v1.30/containers/086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81/start
DEBU[2022-01-10T11:55:43.552067723Z] container mounted via layerStore: &{/var/lib/docker/overlay2/826c78df23cd3bc99913e9d0f78426fe15e9b93e4c5ae683f92842a39482952c/merged 0x344f560 0x344f560}  container=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81
DEBU[2022-01-10T11:55:43.552912809Z] Assigning addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T11:55:43.552973651Z] RequestAddress(LocalDefault/172.18.0.0/16, <nil>, map[])
DEBU[2022-01-10T11:55:43.553026259Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65533, Sequence: (0xc0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:<nil>
DEBU[2022-01-10T11:55:43.561313886Z] Assigning addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T11:55:43.565904466Z] Programming external connectivity on endpoint error-values (8bc07793c0be5196b6c6c8fac9d662826486503d84c9a393e180c9769959f016)
DEBU[2022-01-10T11:55:43.566957234Z] EnableService 086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 START
DEBU[2022-01-10T11:55:43.567003158Z] EnableService 086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 DONE
DEBU[2022-01-10T11:55:43.570363138Z] bundle dir created                            bundle=/var/run/docker/containerd/086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/826c78df23cd3bc99913e9d0f78426fe15e9b93e4c5ae683f92842a39482952c/merged
DEBU[2022-01-10T11:55:43.577312870Z] event published                               ns=moby topic=/containers/create type=containerd.events.ContainerCreate
time="2022-01-10T11:55:43.599712129Z" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
time="2022-01-10T11:55:43.599950679Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
time="2022-01-10T11:55:43.600201167Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
time="2022-01-10T11:55:43.601266058Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 pid=944 runtime=io.containerd.runc.v2
DEBU[2022-01-10T11:55:43.648009404Z] garbage collected                             d=1.142049ms
DEBU[2022-01-10T11:55:43.756585282Z] sandbox set key processing took 65.709707ms for container 086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81
DEBU[2022-01-10T11:55:43.785690280Z] failed to delete task                         error="rpc error: code = NotFound desc = container not created: not found" id=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81
INFO[2022-01-10T11:55:43.786308808Z] shim disconnected                             id=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81
WARN[2022-01-10T11:55:43.786391840Z] cleaning up after shim disconnected           id=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 namespace=moby
INFO[2022-01-10T11:55:43.786465203Z] cleaning up dead shim
WARN[2022-01-10T11:55:43.802849319Z] cleanup warnings time="2022-01-10T11:55:43Z" level=info msg="starting signal loop" namespace=moby pid=985 runtime=io.containerd.runc.v2
DEBU[2022-01-10T11:55:43.803506166Z] event published                               ns=moby topic=/tasks/exit type=containerd.events.TaskExit
DEBU[2022-01-10T11:55:43.803658180Z] event published                               ns=moby topic=/tasks/delete type=containerd.events.TaskDelete
ERRO[2022-01-10T11:55:43.803804251Z] copy shim log                                 error="read /proc/self/fd/13: file already closed"
DEBU[2022-01-10T11:55:43.804853618Z] event                                         module=libcontainerd namespace=moby topic=/tasks/exit
DEBU[2022-01-10T11:55:43.804921764Z] event                                         module=libcontainerd namespace=moby topic=/tasks/delete
ERRO[2022-01-10T11:55:43.804998376Z] stream copy error: reading from a closed fifo
INFO[2022-01-10T11:55:43.806326148Z] ignoring event                                container=086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
ERRO[2022-01-10T11:55:43.805060257Z] stream copy error: reading from a closed fifo
DEBU[2022-01-10T11:55:43.805399937Z] attach: stderr: end
DEBU[2022-01-10T11:55:43.805395759Z] attach: stdout: end
DEBU[2022-01-10T11:55:43.807399980Z] attach done
DEBU[2022-01-10T11:55:43.809764528Z] event published                               ns=moby topic=/containers/delete type=containerd.events.ContainerDelete
DEBU[2022-01-10T11:55:43.817078809Z] Revoking external connectivity on endpoint error-values (8bc07793c0be5196b6c6c8fac9d662826486503d84c9a393e180c9769959f016)
DEBU[2022-01-10T11:55:43.817712158Z] DeleteConntrackEntries purged ipv4:0, ipv6:0
DEBU[2022-01-10T11:55:43.836560091Z] garbage collected                             d=1.266253ms
DEBU[2022-01-10T11:55:43.872421803Z] Releasing addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T11:55:43.872493585Z] ReleaseAddress(LocalDefault/172.18.0.0/16, 172.18.0.2)
DEBU[2022-01-10T11:55:43.872521696Z] Released address PoolID:LocalDefault/172.18.0.0/16, Address:172.18.0.2 Sequence:App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65532, Sequence: (0xe0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:3
ERRO[2022-01-10T11:55:43.882144245Z] 086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 cleanup: failed to delete container from containerd: no such container
WARN[2022-01-10T11:55:43.883828105Z] error locating sandbox id 8e2aff22ecad17b08fe07d5dfdd2f73544c6bc46c1c5bcd1d1e04cc205db5a35: sandbox 8e2aff22ecad17b08fe07d5dfdd2f73544c6bc46c1c5bcd1d1e04cc205db5a35 not found
DEBU[2022-01-10T11:55:43.883930433Z] Failed to unmount 826c78df23cd3bc99913e9d0f78426fe15e9b93e4c5ae683f92842a39482952c overlay: /var/lib/docker/overlay2/826c78df23cd3bc99913e9d0f78426fe15e9b93e4c5ae683f92842a39482952c/merged - no such file or directory  storage-driver=overlay2
ERRO[2022-01-10T11:55:43.884643229Z] 086678ef8b6507782b2cfe88160b89cc43958a438910dcaf9e1352c989d5fd81 cleanup: failed to delete container from containerd: no such container

Compared with daemon logs on containerd v1.5.8

DEBU[2022-01-10T12:02:12.712322630Z] Calling GET /_ping
DEBU[2022-01-10T12:02:12.716382054Z] Calling POST /v1.30/containers/create?name=error-values
DEBU[2022-01-10T12:02:12.716751745Z] form data: {"AttachStderr":true,"AttachStdin":false,"AttachStdout":true,"Cmd":["toto"],"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":null,"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"Init":false,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"busybox","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":false,"StdinOnce":false,"Tty":false,"User":"","Volumes":{},"WorkingDir":""}
DEBU[2022-01-10T12:02:12.736010536Z] container mounted via layerStore: &{/var/lib/docker/overlay2/ea80daf632d86e9659cab1a5596e86dd218347bc8f66b17bd1c1224576a45c19/merged 0x344f560 0x344f560}  container=cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2
DEBU[2022-01-10T12:02:12.752599702Z] Calling POST /v1.30/containers/cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2/attach?stderr=1&stdout=1&stream=1
DEBU[2022-01-10T12:02:12.753067492Z] attach: stderr: begin
DEBU[2022-01-10T12:02:12.753184704Z] attach: stdout: begin
DEBU[2022-01-10T12:02:12.754160119Z] Calling POST /v1.30/containers/cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2/wait?condition=next-exit
DEBU[2022-01-10T12:02:12.755133665Z] Calling POST /v1.30/containers/cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2/start
DEBU[2022-01-10T12:02:12.756214382Z] container mounted via layerStore: &{/var/lib/docker/overlay2/ea80daf632d86e9659cab1a5596e86dd218347bc8f66b17bd1c1224576a45c19/merged 0x344f560 0x344f560}  container=cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2
DEBU[2022-01-10T12:02:12.756791646Z] Assigning addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T12:02:12.756828998Z] RequestAddress(LocalDefault/172.18.0.0/16, <nil>, map[])
DEBU[2022-01-10T12:02:12.756867275Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65533, Sequence: (0xc0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:<nil>
DEBU[2022-01-10T12:02:12.766748462Z] Assigning addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T12:02:12.772726233Z] Programming external connectivity on endpoint error-values (3652e7a42d152e076d3e9c7a8b56be42752d5bc991beb56e04424a52cb2756ca)
DEBU[2022-01-10T12:02:12.773712754Z] EnableService cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 START
DEBU[2022-01-10T12:02:12.773747848Z] EnableService cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 DONE
DEBU[2022-01-10T12:02:12.777222904Z] bundle dir created                            bundle=/var/run/docker/containerd/cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/ea80daf632d86e9659cab1a5596e86dd218347bc8f66b17bd1c1224576a45c19/merged
DEBU[2022-01-10T12:02:12.784246366Z] event published                               ns=moby topic=/containers/create type=containerd.events.ContainerCreate
time="2022-01-10T12:02:12.802831678Z" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 pid=659
DEBU[2022-01-10T12:02:12.826592095Z] garbage collected                             d=1.22325ms
DEBU[2022-01-10T12:02:12.940312888Z] sandbox set key processing took 62.372179ms for container cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2
DEBU[2022-01-10T12:02:12.968289801Z] failed to delete task                         error="rpc error: code = NotFound desc = container not created: not found" id=cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2
INFO[2022-01-10T12:02:12.968870472Z] shim disconnected                             id=cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2
WARN[2022-01-10T12:02:12.968923236Z] cleaning up after shim disconnected           id=cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 namespace=moby
INFO[2022-01-10T12:02:12.968939480Z] cleaning up dead shim
WARN[2022-01-10T12:02:12.984831980Z] cleanup warnings time="2022-01-10T12:02:12Z" level=info msg="starting signal loop" namespace=moby pid=704
ERRO[2022-01-10T12:02:12.985795869Z] copy shim log                                 error="read /proc/self/fd/13: file already closed"
ERRO[2022-01-10T12:02:12.986836541Z] stream copy error: reading from a closed fifo
ERRO[2022-01-10T12:02:12.986993604Z] stream copy error: reading from a closed fifo
DEBU[2022-01-10T12:02:12.987375673Z] attach: stdout: end
DEBU[2022-01-10T12:02:12.987429072Z] attach: stderr: end
DEBU[2022-01-10T12:02:12.987573122Z] attach done
DEBU[2022-01-10T12:02:12.991030130Z] event published                               ns=moby topic=/containers/delete type=containerd.events.ContainerDelete
DEBU[2022-01-10T12:02:12.996804811Z] Revoking external connectivity on endpoint error-values (3652e7a42d152e076d3e9c7a8b56be42752d5bc991beb56e04424a52cb2756ca)
DEBU[2022-01-10T12:02:12.997489421Z] DeleteConntrackEntries purged ipv4:0, ipv6:0
DEBU[2022-01-10T12:02:13.040116843Z] garbage collected                             d=1.349504ms
DEBU[2022-01-10T12:02:13.045231123Z] Releasing addresses for endpoint error-values's interface on network bridge
DEBU[2022-01-10T12:02:13.045257315Z] ReleaseAddress(LocalDefault/172.18.0.0/16, 172.18.0.2)
DEBU[2022-01-10T12:02:13.045273986Z] Released address PoolID:LocalDefault/172.18.0.0/16, Address:172.18.0.2 Sequence:App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65532, Sequence: (0xe0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:3
ERRO[2022-01-10T12:02:13.056842304Z] cb349d813f10483594cefaa9ee3d038b0a9da7338e65315163e9ba3b2576ccd2 cleanup: failed to delete container from containerd: no such container

@thaJeztah
Copy link
Member Author

I cleaned up logs for both the 1.6.0 and 1.5.8 situation (replacing timestamps, container ID's etc.) and did a compare between the two:

containerd-1.5.8.log.txt
containerd-1.6.0.log.txt

Diff between those:

diff --git a/containerd-1.5.8.log b/containerd-1.6.0.log
index 73f052e5e6..ca156f0821 100644
--- a/containerd-1.5.8.log
+++ b/containerd-1.6.0.log
@@ -1,4 +1,3 @@
-DEBU[xxxx] Calling GET /_ping
 DEBU[xxxx] Calling POST /v1.30/containers/create?name=error-values
 DEBU[xxxx] form data: {"AttachStderr":true,"AttachStdin":false,"AttachStdout":true,"Cmd":["toto"],"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":null,"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"Init":false,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"busybox","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":false,"StdinOnce":false,"Tty":false,"User":"","Volumes":{},"WorkingDir":""}
 DEBU[xxxx] container mounted via layerStore: &{/var/lib/docker/overlay2/yyyy/merged 0x344f560 0x344f560}  container=yyyy
@@ -17,16 +16,24 @@ DEBU[xxxx] EnableService yyyy START
 DEBU[xxxx] EnableService yyyy DONE
 DEBU[xxxx] bundle dir created                            bundle=/var/run/docker/containerd/yyyy module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/yyyy/merged
 DEBU[xxxx] event published                               ns=moby topic=/containers/create type=containerd.events.ContainerCreate
-time="xxxx" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/yyyy pid=659
+time="xxxx" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
+time="xxxx" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
+time="xxxx" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
+time="xxxx" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/yyyy pid=944 runtime=io.containerd.runc.v2
 DEBU[xxxx] garbage collected                             d=1.xxxxms
 DEBU[xxxx] sandbox set key processing took 62.xxxxms for container yyyy
 DEBU[xxxx] failed to delete task                         error="rpc error: code = NotFound desc = container not created: not found" id=yyyy
 INFO[xxxx] shim disconnected                             id=yyyy
 WARN[xxxx] cleaning up after shim disconnected           id=yyyy namespace=moby
 INFO[xxxx] cleaning up dead shim
-WARN[xxxx] cleanup warnings time="xxxx" level=info msg="starting signal loop" namespace=moby pid=xxxx
+WARN[xxxx] cleanup warnings time="xxxx" level=info msg="starting signal loop" namespace=moby pid=xxxx runtime=io.containerd.runc.v2
+DEBU[xxxx] event published                               ns=moby topic=/tasks/exit type=containerd.events.TaskExit
+DEBU[xxxx] event published                               ns=moby topic=/tasks/delete type=containerd.events.TaskDelete
 ERRO[xxxx] copy shim log                                 error="read /proc/self/fd/13: file already closed"
+DEBU[xxxx] event                                         module=libcontainerd namespace=moby topic=/tasks/exit
+DEBU[xxxx] event                                         module=libcontainerd namespace=moby topic=/tasks/delete
 ERRO[xxxx] stream copy error: reading from a closed fifo
+INFO[xxxx] ignoring event                                container=yyyy module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
 ERRO[xxxx] stream copy error: reading from a closed fifo
 DEBU[xxxx] attach: stdout: end
 DEBU[xxxx] attach: stderr: end
@@ -39,3 +46,6 @@ DEBU[xxxx] Releasing addresses for endpoint error-values's interface on network
 DEBU[xxxx] ReleaseAddress(LocalDefault/172.18.0.0/16, 172.18.0.2)
 DEBU[xxxx] Released address PoolID:LocalDefault/172.18.0.0/16, Address:172.18.0.2 Sequence:App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65532, Sequence: (0xe0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:3
 ERRO[xxxx] yyyy cleanup: failed to delete container from containerd: no such container
+WARN[xxxx] error locating sandbox id yyyy: sandbox yyyy not found
+DEBU[xxxx] Failed to unmount yyyy overlay: /var/lib/docker/overlay2/yyyy/merged - no such file or directory  storage-driver=overlay2
+ERRO[xxxx] yyyy cleanup: failed to delete container from containerd: no such container

@thaJeztah
Copy link
Member Author

containerd/containerd#6465 was merged, which should address the regression, so I pushed a temporary commit to update the Linux version to current main;

[WIP] update containerd binary to v1.6.0-rc.1-4-g731518417

This contains a fix for the regression we saw on Linux; containerd/containerd@v1.6.0-rc.1...v1.6.0-rc.1-4-g731518417

@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-beta.5 update containerd binary to v1.6.0-rc.4 Feb 15, 2022
@Mohsen7s
Copy link

containerd 1.6.0 already released yesterday which it solve a lot of bugs with experimental checkpoint feature.
Can we have finally ship containerd 1.6.0 ?

@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0-rc.4 update containerd binary to v1.6.0 Feb 18, 2022
@AkihiroSuda
Copy link
Member

Could you rebase and update to v1.6.1?
LGTM then

@tianon
Copy link
Member

tianon commented Mar 11, 2022

Given @AkihiroSuda showing me what I was doing wrong in containerd/containerd#6659 (comment) (thanks again! ❤️), I'm +1 on updating to 1.6.1 also.

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
@thaJeztah thaJeztah changed the title update containerd binary to v1.6.0 update containerd binary to v1.6.1 Mar 11, 2022
@thaJeztah
Copy link
Member Author

Updated to v1.6.1

@thaJeztah thaJeztah added this to the 21.xx milestone Mar 11, 2022
@thaJeztah thaJeztah marked this pull request as ready for review March 12, 2022 00:24
@thaJeztah thaJeztah requested a review from tianon as a code owner March 12, 2022 00:24
@thaJeztah
Copy link
Member Author

@cpuguy83 @tonistiigi @AkihiroSuda we all ok with going to v1.6 for the next release?

Copy link
Member

@cpuguy83 cpuguy83 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@cpuguy83 cpuguy83 merged commit 82f2073 into moby:master Mar 12, 2022
@thaJeztah thaJeztah deleted the containerd_binary_1.6 branch March 12, 2022 20:14
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

6 participants