Skip to content

rootless: race on starting containers in dind #38817

Closed
Closed
rootless: race on starting containers in dind#38817
Labels
area/rootlessRootless Modekind/bugBugs are bugs. The cause may or may not be known at triage time so debugging may be needed.
@tonistiigi

Description

@tonistiigi
tonistiigi
opened on Mar 2, 2019

Tried to use dind in rootless mode. Starting dockerd with --rootless.

There seems to be a race on doing docker run. Very short lived containers work. Eg. docker run alpine ls and docker run alpine usleep 500 works but docker run alpine usleep 1000 fails.

docker: Error response from daemon: cgroups: cgroup deleted: unknown.
ERRO[0000] error waiting for container: context canceled

time="2019-03-02T03:11:41.744381969Z" level=debug msg="Calling GET /_ping"
time="2019-03-02T03:11:41.745662780Z" level=debug msg="Calling POST /v1.30/containers/create"
time="2019-03-02T03:11:41.745994379Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":false,\"AttachStdout\":true,\"Cmd\":[\"usleep\",\"700\"],\"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,\"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\":\"alpine\",\"Labels\":{},\"NetworkingConfig\":{\"EndpointsConfig\":{}},\"OnBuild\":null,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"User\":\"\",\"Volumes\":{},\"WorkingDir\":\"\"}"
time="2019-03-02T03:11:41.772914021Z" level=debug msg="container mounted via layerStore: &{/var/lib/docker/overlay2/091d5321e74d78d91c7411147d451455553a4c77c10267777be705a3034288a9/merged 0x3abe3e0 0x3abe3e0}"
time="2019-03-02T03:11:41.796250222Z" level=debug msg="Calling POST /v1.30/containers/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d/attach?stderr=1&stdout=1&stream=1"
time="2019-03-02T03:11:41.796477833Z" level=debug msg="attach: stderr: begin"
time="2019-03-02T03:11:41.796480789Z" level=debug msg="attach: stdout: begin"
time="2019-03-02T03:11:41.797821759Z" level=debug msg="Calling POST /v1.30/containers/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d/wait?condition=next-exit"
time="2019-03-02T03:11:41.798828356Z" level=debug msg="Calling POST /v1.30/containers/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d/start"
time="2019-03-02T03:11:41.800397892Z" level=debug msg="container mounted via layerStore: &{/var/lib/docker/overlay2/091d5321e74d78d91c7411147d451455553a4c77c10267777be705a3034288a9/merged 0x3abe3e0 0x3abe3e0}"
time="2019-03-02T03:11:41.800827456Z" level=debug msg="Assigning addresses for endpoint mystifying_engelbart's interface on network bridge"
time="2019-03-02T03:11:41.800897552Z" level=debug msg="RequestAddress(LocalDefault/172.18.0.0/16, <nil>, map[])"
time="2019-03-02T03:11:41.800947440Z" level=debug msg="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:3 Serial:false PrefAddress:<nil> "
time="2019-03-02T03:11:41.804302303Z" level=debug msg="Assigning addresses for endpoint mystifying_engelbart's interface on network bridge"
time="2019-03-02T03:11:41.808763153Z" level=debug msg="Programming external connectivity on endpoint mystifying_engelbart (af5c1dc2f12be9c3c9ac270e336630c1f5a2a841d1a0fb3ff056ad3bf2f46a42)"
time="2019-03-02T03:11:41.809488084Z" level=debug msg="EnableService 318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d START"
time="2019-03-02T03:11:41.809519968Z" level=debug msg="EnableService 318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d DONE"
time="2019-03-02T03:11:41.812112107Z" level=debug msg="bundle dir created" bundle=/var/run/docker/containerd/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/091d5321e74d78d91c7411147d451455553a4c77c10267777be705a3034288a9/merged
time="2019-03-02T03:11:41.815239507Z" level=debug msg="event published" ns=moby topic="/containers/create" type=containerd.events.ContainerCreate
time="2019-03-02T03:11:41.820351807Z" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d/shim.sock" debug=true pid=9472
time="2019-03-02T03:11:41Z" level=debug msg="registering ttrpc server"
time="2019-03-02T03:11:41Z" level=debug msg="serving api on unix socket" socket="[inherited from parent]"
time="2019-03-02T03:11:41.991294876Z" level=debug msg="sandbox set key processing took 84.690029ms for container 318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d"
time="2019-03-02T03:11:42.093091891Z" level=debug msg="event published" ns=moby topic="/tasks/create" type=containerd.events.TaskCreate
time="2019-03-02T03:11:42.093682501Z" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/create
time="2019-03-02T03:11:42.114589886Z" level=error msg="stream copy error: read /proc/self/fd/22: file already closed"
time="2019-03-02T03:11:42.114699201Z" level=error msg="stream copy error: read /proc/self/fd/23: file already closed"
time="2019-03-02T03:11:42.114856615Z" level=debug msg="attach: stdout: end"
time="2019-03-02T03:11:42.114860048Z" level=debug msg="attach: stderr: end"
time="2019-03-02T03:11:42.114892957Z" level=debug msg="attach done"
time="2019-03-02T03:11:42.124127328Z" level=error msg="failed to delete task after fail start" container=318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d error="task must be stopped before deletion: running: failed precondition" module=libcontainerd namespace=moby
time="2019-03-02T03:11:42.132271569Z" level=error msg="failed to delete failed start container" container=318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d error="cannot delete running task 318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d: failed precondition"
time="2019-03-02T03:11:42.136896063Z" level=debug msg="Revoking external connectivity on endpoint mystifying_engelbart (af5c1dc2f12be9c3c9ac270e336630c1f5a2a841d1a0fb3ff056ad3bf2f46a42)"
time="2019-03-02T03:11:42.138816900Z" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2019-03-02T03:11:42.189818111Z" level=debug msg="event published" ns=moby topic="/tasks/exit" type=containerd.events.TaskExit
time="2019-03-02T03:11:42.190200722Z" level=debug msg=event module=libcontainerd namespace=moby topic=/tasks/exit
time="2019-03-02T03:11:42.190314159Z" level=warning msg="Ignoring Exit Event, no such exec command found" container=318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d exec-id=318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d exec-pid=9489
time="2019-03-02T03:11:42.246756496Z" level=debug msg="Releasing addresses for endpoint mystifying_engelbart's interface on network bridge"
time="2019-03-02T03:11:42.246818581Z" level=debug msg="ReleaseAddress(LocalDefault/172.18.0.0/16, 172.18.0.2)"
time="2019-03-02T03:11:42.246877761Z" level=debug msg="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"
time="2019-03-02T03:11:42.321744393Z" level=error msg="318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d cleanup: failed to delete container from containerd: cannot delete running task 318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d: failed precondition"
time="2019-03-02T03:11:42.321810393Z" level=error msg="Handler for POST /v1.30/containers/318f521d01f16fe9391dee640df1c68c06501a9699fba28e28ad5eca0831d98d/start returned error: cgroups: cgroup deleted: unknown"

Version inside dind 8aca18d

@AkihiroSuda

Metadata

Metadata

Assignees

No one assigned

    Labels

    area/rootlessRootless Modekind/bugBugs are bugs. The cause may or may not be known at triage time so debugging may be needed.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions