Dind gitlab-runner service doesn't start up suddenly

I’m running gitlab ce 12.1.0. Last night I upgraded from 11 to this today. At some point during the upgrade, my ci jobs that used dind service started failing. The logs are below. I’ve googled for hours and I’ve tried a bunch of stuff like recreating the runner, restarting the comp, bringing up the image manually and checking the logs. I can’t find any answer. Please can someone help?

My only potential thought is does the gitlab-runner runner version need to match the gitlab version?

Running with gitlab-runner 11.3.1~beta.4.g0aa5179e (0aa5179e)
  on DIND sMQfGXoN
Using Docker executor with image docker:stable ...
Starting service docker:dind ...
Pulling docker image docker:dind ...
Using docker image sha256:6ce0d31cf4d670f84b0f74b1b15910f9e3fde4105232e14b0d360a6a49c05362 for docker:dind ...
Waiting for services to be up and running...

*** WARNING: Service runner-sMQfGXoN-project-26-concurrent-0-docker-0 probably didn't start properly.

Health check error:
service "runner-sMQfGXoN-project-26-concurrent-0-docker-0-wait-for-service" timeout

Health check container logs:


Service container logs:
2019-07-23T04:08:54.663075791Z Generating RSA private key, 4196 bit long modulus (2 primes)
2019-07-23T04:08:55.295724183Z ..........................................................................++++
2019-07-23T04:08:55.746325391Z .....................................................++++
2019-07-23T04:08:55.746716505Z e is 65537 (0x010001)
2019-07-23T04:08:55.777346587Z Generating RSA private key, 4196 bit long modulus (2 primes)
2019-07-23T04:08:56.138878139Z ...........................................................++++
2019-07-23T04:08:56.767863202Z ......................................................................................................++++
2019-07-23T04:08:56.768312642Z e is 65537 (0x010001)
2019-07-23T04:08:56.797606109Z Signature ok
2019-07-23T04:08:56.797625213Z subject=CN = docker:dind server
2019-07-23T04:08:56.797782030Z Getting CA Private Key
2019-07-23T04:08:56.813762850Z /certs/server/cert.pem: OK
2019-07-23T04:08:56.816479259Z Generating RSA private key, 4196 bit long modulus (2 primes)
2019-07-23T04:08:56.925009491Z ................++++
2019-07-23T04:08:57.797329444Z ..............................................................................................................................................++++
2019-07-23T04:08:57.797720954Z e is 65537 (0x010001)
2019-07-23T04:08:57.821184439Z Signature ok
2019-07-23T04:08:57.821200782Z subject=CN = docker:dind client
2019-07-23T04:08:57.821328508Z Getting CA Private Key
2019-07-23T04:08:57.836019258Z /certs/client/cert.pem: OK
2019-07-23T04:08:57.996656638Z time="2019-07-23T04:08:57.996529879Z" level=info msg="Starting up"
2019-07-23T04:08:58.000680295Z time="2019-07-23T04:08:58.000622383Z" level=warning msg="could not change group /var/run/docker.sock to docker: group docker not found"
2019-07-23T04:08:58.003801730Z time="2019-07-23T04:08:58.003728264Z" level=info msg="libcontainerd: started new containerd process" pid=49
2019-07-23T04:08:58.003811298Z time="2019-07-23T04:08:58.003763806Z" level=info msg="parsed scheme: \"unix\"" module=grpc
2019-07-23T04:08:58.003814797Z time="2019-07-23T04:08:58.003774390Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
2019-07-23T04:08:58.003847100Z time="2019-07-23T04:08:58.003795679Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }" module=grpc
2019-07-23T04:08:58.003855571Z time="2019-07-23T04:08:58.003823537Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
2019-07-23T04:08:58.006986652Z time="2019-07-23T04:08:58.004383784Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0001b9ce0, CONNECTING" module=grpc
2019-07-23T04:08:58.087188654Z time="2019-07-23T04:08:58.087084563Z" level=info msg="starting containerd" revision=894b81a4b802e4eb2a91d1ce216b8817763c29fb version=v1.2.6 
2019-07-23T04:08:58.087542840Z time="2019-07-23T04:08:58.087504938Z" level=info msg="loading plugin "io.containerd.content.v1.content"..." type=io.containerd.content.v1 
2019-07-23T04:08:58.087606181Z time="2019-07-23T04:08:58.087576346Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.btrfs"..." type=io.containerd.snapshotter.v1 
2019-07-23T04:08:58.087746376Z time="2019-07-23T04:08:58.087711717Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.btrfs" error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter" 
2019-07-23T04:08:58.087753703Z time="2019-07-23T04:08:58.087724576Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.aufs"..." type=io.containerd.snapshotter.v1 
2019-07-23T04:08:58.092148741Z time="2019-07-23T04:08:58.092071058Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.aufs" error="modprobe aufs failed: "ip: can't find device 'aufs'\naufs                  241664 223 \nmodprobe: can't change directory to '/lib/modules': No such file or directory\n": exit status 1" 
2019-07-23T04:08:58.092166596Z time="2019-07-23T04:08:58.092088759Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.native"..." type=io.containerd.snapshotter.v1 
2019-07-23T04:08:58.092214517Z time="2019-07-23T04:08:58.092171512Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.overlayfs"..." type=io.containerd.snapshotter.v1 
2019-07-23T04:08:58.092333630Z time="2019-07-23T04:08:58.092292234Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.zfs"..." type=io.containerd.snapshotter.v1 
2019-07-23T04:08:58.092482000Z time="2019-07-23T04:08:58.092445665Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.zfs" error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter" 
2019-07-23T04:08:58.092490556Z time="2019-07-23T04:08:58.092454831Z" level=info msg="loading plugin "io.containerd.metadata.v1.bolt"..." type=io.containerd.metadata.v1 
2019-07-23T04:08:58.092531933Z time="2019-07-23T04:08:58.092494168Z" level=warning msg="could not use snapshotter btrfs in metadata plugin" error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter" 
2019-07-23T04:08:58.092539695Z time="2019-07-23T04:08:58.092499987Z" level=warning msg="could not use snapshotter aufs in metadata plugin" error="modprobe aufs failed: "ip: can't find device 'aufs'\naufs                  241664 223 \nmodprobe: can't change directory to '/lib/modules': No such file or directory\n": exit status 1" 
2019-07-23T04:08:58.092545514Z time="2019-07-23T04:08:58.092505168Z" level=warning msg="could not use snapshotter zfs in metadata plugin" error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter" 
2019-07-23T04:08:58.125682211Z time="2019-07-23T04:08:58.125592083Z" level=info msg="loading plugin "io.containerd.differ.v1.walking"..." type=io.containerd.differ.v1 
2019-07-23T04:08:58.125708798Z time="2019-07-23T04:08:58.125624301Z" level=info msg="loading plugin "io.containerd.gc.v1.scheduler"..." type=io.containerd.gc.v1 
2019-07-23T04:08:58.125716991Z time="2019-07-23T04:08:58.125670246Z" level=info msg="loading plugin "io.containerd.service.v1.containers-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125732680Z time="2019-07-23T04:08:58.125686419Z" level=info msg="loading plugin "io.containerd.service.v1.content-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125738934Z time="2019-07-23T04:08:58.125697299Z" level=info msg="loading plugin "io.containerd.service.v1.diff-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125743405Z time="2019-07-23T04:08:58.125711263Z" level=info msg="loading plugin "io.containerd.service.v1.images-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125767715Z time="2019-07-23T04:08:58.125724494Z" level=info msg="loading plugin "io.containerd.service.v1.leases-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125780311Z time="2019-07-23T04:08:58.125737134Z" level=info msg="loading plugin "io.containerd.service.v1.namespaces-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125811569Z time="2019-07-23T04:08:58.125753392Z" level=info msg="loading plugin "io.containerd.service.v1.snapshots-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.125822521Z time="2019-07-23T04:08:58.125766952Z" level=info msg="loading plugin "io.containerd.runtime.v1.linux"..." type=io.containerd.runtime.v1 
2019-07-23T04:08:58.126010406Z time="2019-07-23T04:08:58.125959448Z" level=info msg="loading plugin "io.containerd.runtime.v2.task"..." type=io.containerd.runtime.v2 
2019-07-23T04:08:58.126704472Z time="2019-07-23T04:08:58.126649643Z" level=info msg="loading plugin "io.containerd.monitor.v1.cgroups"..." type=io.containerd.monitor.v1 
2019-07-23T04:08:58.127180825Z time="2019-07-23T04:08:58.127127982Z" level=info msg="loading plugin "io.containerd.service.v1.tasks-service"..." type=io.containerd.service.v1 
2019-07-23T04:08:58.127189786Z time="2019-07-23T04:08:58.127149863Z" level=info msg="loading plugin "io.containerd.internal.v1.restart"..." type=io.containerd.internal.v1 
2019-07-23T04:08:58.127230486Z time="2019-07-23T04:08:58.127190173Z" level=info msg="loading plugin "io.containerd.grpc.v1.containers"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127237272Z time="2019-07-23T04:08:58.127204919Z" level=info msg="loading plugin "io.containerd.grpc.v1.content"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127283607Z time="2019-07-23T04:08:58.127220426Z" level=info msg="loading plugin "io.containerd.grpc.v1.diff"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127290170Z time="2019-07-23T04:08:58.127232892Z" level=info msg="loading plugin "io.containerd.grpc.v1.events"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127294553Z time="2019-07-23T04:08:58.127244792Z" level=info msg="loading plugin "io.containerd.grpc.v1.healthcheck"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127298683Z time="2019-07-23T04:08:58.127257531Z" level=info msg="loading plugin "io.containerd.grpc.v1.images"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127333423Z time="2019-07-23T04:08:58.127269936Z" level=info msg="loading plugin "io.containerd.grpc.v1.leases"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127339487Z time="2019-07-23T04:08:58.127283635Z" level=info msg="loading plugin "io.containerd.grpc.v1.namespaces"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127348109Z time="2019-07-23T04:08:58.127297792Z" level=info msg="loading plugin "io.containerd.internal.v1.opt"..." type=io.containerd.internal.v1 
2019-07-23T04:08:58.127641053Z time="2019-07-23T04:08:58.127592429Z" level=info msg="loading plugin "io.containerd.grpc.v1.snapshots"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127649266Z time="2019-07-23T04:08:58.127610991Z" level=info msg="loading plugin "io.containerd.grpc.v1.tasks"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127681423Z time="2019-07-23T04:08:58.127625946Z" level=info msg="loading plugin "io.containerd.grpc.v1.version"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.127690882Z time="2019-07-23T04:08:58.127642499Z" level=info msg="loading plugin "io.containerd.grpc.v1.introspection"..." type=io.containerd.grpc.v1 
2019-07-23T04:08:58.128123846Z time="2019-07-23T04:08:58.128072484Z" level=info msg=serving... address="/var/run/docker/containerd/containerd-debug.sock" 
2019-07-23T04:08:58.128216627Z time="2019-07-23T04:08:58.128164936Z" level=info msg=serving... address="/var/run/docker/containerd/containerd.sock" 
2019-07-23T04:08:58.128222858Z time="2019-07-23T04:08:58.128178501Z" level=info msg="containerd successfully booted in 0.041564s" 
2019-07-23T04:08:58.139275467Z time="2019-07-23T04:08:58.139173202Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0001b9ce0, READY" module=grpc
2019-07-23T04:08:58.143133916Z time="2019-07-23T04:08:58.143073674Z" level=info msg="Setting the storage driver from the $DOCKER_DRIVER environment variable (overlay2)"
2019-07-23T04:08:58.143284143Z time="2019-07-23T04:08:58.143235775Z" level=info msg="parsed scheme: \"unix\"" module=grpc
2019-07-23T04:08:58.143294927Z time="2019-07-23T04:08:58.143245993Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
2019-07-23T04:08:58.143331705Z time="2019-07-23T04:08:58.143272324Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }" module=grpc
2019-07-23T04:08:58.143340343Z time="2019-07-23T04:08:58.143284498Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
2019-07-23T04:08:58.143397628Z time="2019-07-23T04:08:58.143339027Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0008c01c0, CONNECTING" module=grpc
2019-07-23T04:08:58.143651794Z time="2019-07-23T04:08:58.143604163Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0008c01c0, READY" module=grpc
2019-07-23T04:08:58.144062028Z time="2019-07-23T04:08:58.144014629Z" level=info msg="parsed scheme: \"unix\"" module=grpc
2019-07-23T04:08:58.144071328Z time="2019-07-23T04:08:58.144038657Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
2019-07-23T04:08:58.144100462Z time="2019-07-23T04:08:58.144055096Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }" module=grpc
2019-07-23T04:08:58.144107102Z time="2019-07-23T04:08:58.144072857Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
2019-07-23T04:08:58.144186491Z time="2019-07-23T04:08:58.144123881Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0007930d0, CONNECTING" module=grpc
2019-07-23T04:08:58.144194284Z time="2019-07-23T04:08:58.144145835Z" level=info msg="blockingPicker: the picked transport is not ready, loop back to repick" module=grpc
2019-07-23T04:08:58.144745332Z time="2019-07-23T04:08:58.144701157Z" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0007930d0, READY" module=grpc
2019-07-23T04:08:58.212968035Z time="2019-07-23T04:08:58.212874236Z" level=warning msg="Your kernel does not support swap memory limit"
2019-07-23T04:08:58.212989231Z time="2019-07-23T04:08:58.212893989Z" level=warning msg="Your kernel does not support cgroup rt period"
2019-07-23T04:08:58.212994126Z time="2019-07-23T04:08:58.212900747Z" level=warning msg="Your kernel does not support cgroup rt runtime"
2019-07-23T04:08:58.214511684Z time="2019-07-23T04:08:58.214468457Z" level=info msg="Loading containers: start."
2019-07-23T04:08:58.221164726Z time="2019-07-23T04:08:58.221060450Z" level=warning msg="Running modprobe bridge br_netfilter failed with message: ip: can't find device 'bridge'\nbridge                151552  1 br_netfilter\nstp                    16384  1 bridge\nllc                    16384  2 bridge,stp\nip: can't find device 'br_netfilter'\nbr_netfilter           24576  0 \nbridge                151552  1 br_netfilter\nmodprobe: can't change directory to '/lib/modules': No such file or directory\n, error: exit status 1"
2019-07-23T04:08:58.224826637Z time="2019-07-23T04:08:58.224721871Z" level=warning msg="Running modprobe nf_nat failed with message: `ip: can't find device 'nf_nat'\nnf_nat_masquerade_ipv4    16384  1 ipt_MASQUERADE\nnf_nat_ipv4            16384  1 iptable_nat\nnf_nat                 32768  3 xt_nat,nf_nat_masquerade_ipv4,nf_nat_ipv4\nnf_conntrack          131072  8 xt_nat,ipt_MASQUERADE,nf_nat_masquerade_ipv4,nf_conntrack_netlink,nf_conntrack_ipv4,nf_nat_ipv4,xt_conntrack,nf_nat\nlibcrc32c              16384  3 nf_nat,nf_conntrack,raid456\nmodprobe: can't change directory to '/lib/modules': No such file or directory`, error: exit status 1"
2019-07-23T04:08:58.228275697Z time="2019-07-23T04:08:58.228172334Z" level=warning msg="Running modprobe xt_conntrack failed with message: `ip: can't find device 'xt_conntrack'\nxt_conntrack           16384  2 \nnf_conntrack          131072  8 xt_nat,ipt_MASQUERADE,nf_nat_masquerade_ipv4,nf_conntrack_netlink,nf_conntrack_ipv4,nf_nat_ipv4,xt_conntrack,nf_nat\nx_tables               40960  7 xt_nat,xt_tcpudp,ipt_MASQUERADE,xt_addrtype,iptable_filter,xt_conntrack,ip_tables\nmodprobe: can't change directory to '/lib/modules': No such file or directory`, error: exit status 1"
2019-07-23T04:08:58.510154201Z time="2019-07-23T04:08:58.510059591Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address"
2019-07-23T04:08:58.743066875Z time="2019-07-23T04:08:58.742978826Z" level=info msg="Loading containers: done."
2019-07-23T04:08:58.835866457Z time="2019-07-23T04:08:58.835778217Z" level=info msg="Docker daemon" commit=aeac9490dc graphdriver(s)=overlay2 version=19.03.0
2019-07-23T04:08:58.835958271Z time="2019-07-23T04:08:58.835910339Z" level=info msg="Daemon has completed initialization"
2019-07-23T04:08:58.902244966Z time="2019-07-23T04:08:58.902113298Z" level=info msg="API listen on [::]:2376"
2019-07-23T04:08:58.902377983Z time="2019-07-23T04:08:58.902161705Z" level=info msg="API listen on /var/run/docker.sock"

We’re seeing something similar, but it wasn’t caused by an upgrade. dind just suddenly stopped working for all projects at around 01:00 CET.

This might have something to do with it: Gitlab shared runner can not connect to Docker daemon and leaks secrets

edit: just tested the workaround, seems to help me atm.

variables:
  DOCKER_TLS_CERTDIR: ""

Thank you kindly. The workaround works for me too.

This workaround seems to have worked for me in only one stage (where it still gives that warning). I have another stage, where I use dind to tag and push the image from the GitLab registry to another one. The latter stage is still failing for me despite setting the DOCKER_TLS_CERTDIR and using an older version of docker:18-git.

This Workaround works for me too.
Im using the image “docker:stable” and service “docker:stable-dind”

Docker just updated version to 19.03 as well as docker:dind. In new version TLS enabled by default. To override this behavior variable DOCKER_TLS_CERTDIR: "" should be passed to gitlab-ci.yml
Previous version, 18-09 had TLS disabled by default.

Its possible to use docker:18-dind tag for docker-in-docker builds, a previous dind version. But it will deprecates soon, I think.
My builds are working now, with a new docker:19-dind, but still got warnings at service start.

e[0;me[0KStarting service docker:stable-dind …
e[0;me[0KPulling docker image docker:stable-dind …
e[0;me[0KUsing docker image sha256:fd0c64832f7e46b63a180e6000dbba7ad7a63542c5764841cba73429ba74a39e for docker:stable-dind …
e[0;me[0KWaiting for services to be up and running…
e[0;m
e[0;33m*** WARNING:e[0;m Service runner-5LWtszwS-project-8473061-concurrent-0-docker-0 probably didn’t start properly.

Health check error:
service “runner-5LWtszwS-project-8473061-concurrent-0-docker-0-wait-for-service” timeout

Health check container logs:

Service container logs:
2019-07-26T14:47:13.321015061Z time=“2019-07-26T14:47:13.319967283Z” level=info msg=“Starting up”
2019-07-26T14:47:13.321989660Z time=“2019-07-26T14:47:13.321925807Z” level=warning msg=“could not change group /var/run/docker.sock to docker: group docker not found”
2019-07-26T14:47:13.322610143Z time=“2019-07-26T14:47:13.322060920Z” level=warning msg="[!] DON’T BIND ON ANY IP ADDRESS WITHOUT setting --tlsverify IF YOU DON’T KNOW WHAT YOU’RE DOING [!]"
2019-07-26T14:47:13.322837043Z time=“2019-07-26T14:47:13.322777019Z” level=info msg=“libcontainerd: started new containerd process” pid=20
2019-07-26T14:47:13.322885438Z time=“2019-07-26T14:47:13.322813214Z” level=info msg=“parsed scheme: “unix”” module=grpc
2019-07-26T14:47:13.322891712Z time=“2019-07-26T14:47:13.322822659Z” level=info msg=“scheme “unix” not registered, fallback to default scheme” module=grpc
2019-07-26T14:47:13.322894513Z time=“2019-07-26T14:47:13.322840430Z” level=info msg=“ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0 }] }” module=grpc
2019-07-26T14:47:13.322897327Z time=“2019-07-26T14:47:13.322850320Z” level=info msg=“ClientConn switching balancer to “pick_first”” module=grpc
2019-07-26T14:47:13.322980504Z time=“2019-07-26T14:47:13.322907738Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc000612100, CONNECTING” module=grpc
2019-07-26T14:47:13.334791584Z time=“2019-07-26T14:47:13.334711763Z” level=info msg=“starting containerd” revision=894b81a4b802e4eb2a91d1ce216b8817763c29fb version=v1.2.6
2019-07-26T14:47:13.335039997Z time=“2019-07-26T14:47:13.334993558Z” level=info msg=“loading plugin “io.containerd.content.v1.content”…” type=io.containerd.content.v1
2019-07-26T14:47:13.335098841Z time=“2019-07-26T14:47:13.335059269Z” level=info msg=“loading plugin “io.containerd.snapshotter.v1.btrfs”…” type=io.containerd.snapshotter.v1
2019-07-26T14:47:13.335271159Z time=“2019-07-26T14:47:13.335225691Z” level=warning msg=“failed to load plugin io.containerd.snapshotter.v1.btrfs” error=“path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter”
2019-07-26T14:47:13.335285411Z time=“2019-07-26T14:47:13.335238204Z” level=info msg=“loading plugin “io.containerd.snapshotter.v1.aufs”…” type=io.containerd.snapshotter.v1
2019-07-26T14:47:13.338620057Z time=“2019-07-26T14:47:13.338555460Z” level=warning msg=“failed to load plugin io.containerd.snapshotter.v1.aufs” error=“modprobe aufs failed: “ip: can’t find device ‘aufs’\naufs 241664 0 \nmodprobe: can’t change directory to ‘/lib/modules’: No such file or directory\n”: exit status 1”
2019-07-26T14:47:13.338631981Z time=“2019-07-26T14:47:13.338570196Z” level=info msg=“loading plugin “io.containerd.snapshotter.v1.native”…” type=io.containerd.snapshotter.v1
2019-07-26T14:47:13.338661649Z time=“2019-07-26T14:47:13.338628203Z” level=info msg=“loading plugin “io.containerd.snapshotter.v1.overlayfs”…” type=io.containerd.snapshotter.v1
2019-07-26T14:47:13.338760121Z time=“2019-07-26T14:47:13.338722648Z” level=info msg=“loading plugin “io.containerd.snapshotter.v1.zfs”…” type=io.containerd.snapshotter.v1
2019-07-26T14:47:13.338905289Z time=“2019-07-26T14:47:13.338868066Z” level=warning msg=“failed to load plugin io.containerd.snapshotter.v1.zfs” error=“path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter”
2019-07-26T14:47:13.338917116Z time=“2019-07-26T14:47:13.338878733Z” level=info msg=“loading plugin “io.containerd.metadata.v1.bolt”…” type=io.containerd.metadata.v1
2019-07-26T14:47:13.338940939Z time=“2019-07-26T14:47:13.338908822Z” level=warning msg=“could not use snapshotter btrfs in metadata plugin” error=“path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter”
2019-07-26T14:47:13.338945849Z time=“2019-07-26T14:47:13.338916672Z” level=warning msg=“could not use snapshotter aufs in metadata plugin” error=“modprobe aufs failed: “ip: can’t find device ‘aufs’\naufs 241664 0 \nmodprobe: can’t change directory to ‘/lib/modules’: No such file or directory\n”: exit status 1”
2019-07-26T14:47:13.338948849Z time=“2019-07-26T14:47:13.338923511Z” level=warning msg=“could not use snapshotter zfs in metadata plugin” error=“path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter”
2019-07-26T14:47:13.344782294Z time=“2019-07-26T14:47:13.344732132Z” level=info msg=“loading plugin “io.containerd.differ.v1.walking”…” type=io.containerd.differ.v1
2019-07-26T14:47:13.344791296Z time=“2019-07-26T14:47:13.344749319Z” level=info msg=“loading plugin “io.containerd.gc.v1.scheduler”…” type=io.containerd.gc.v1
2019-07-26T14:47:13.344797809Z time=“2019-07-26T14:47:13.344777359Z” level=info msg=“loading plugin “io.containerd.service.v1.containers-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344808172Z time=“2019-07-26T14:47:13.344792004Z” level=info msg=“loading plugin “io.containerd.service.v1.content-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344817976Z time=“2019-07-26T14:47:13.344803465Z” level=info msg=“loading plugin “io.containerd.service.v1.diff-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344873783Z time=“2019-07-26T14:47:13.344815450Z” level=info msg=“loading plugin “io.containerd.service.v1.images-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344879332Z time=“2019-07-26T14:47:13.344836987Z” level=info msg=“loading plugin “io.containerd.service.v1.leases-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344882889Z time=“2019-07-26T14:47:13.344849615Z” level=info msg=“loading plugin “io.containerd.service.v1.namespaces-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344886493Z time=“2019-07-26T14:47:13.344860310Z” level=info msg=“loading plugin “io.containerd.service.v1.snapshots-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.344895532Z time=“2019-07-26T14:47:13.344872781Z” level=info msg=“loading plugin “io.containerd.runtime.v1.linux”…” type=io.containerd.runtime.v1
2019-07-26T14:47:13.345017187Z time=“2019-07-26T14:47:13.344978897Z” level=info msg=“loading plugin “io.containerd.runtime.v2.task”…” type=io.containerd.runtime.v2
2019-07-26T14:47:13.345075115Z time=“2019-07-26T14:47:13.345051471Z” level=info msg=“loading plugin “io.containerd.monitor.v1.cgroups”…” type=io.containerd.monitor.v1
2019-07-26T14:47:13.345437591Z time=“2019-07-26T14:47:13.345381114Z” level=info msg=“loading plugin “io.containerd.service.v1.tasks-service”…” type=io.containerd.service.v1
2019-07-26T14:47:13.345448131Z time=“2019-07-26T14:47:13.345409990Z” level=info msg=“loading plugin “io.containerd.internal.v1.restart”…” type=io.containerd.internal.v1
2019-07-26T14:47:13.345492086Z time=“2019-07-26T14:47:13.345451786Z” level=info msg=“loading plugin “io.containerd.grpc.v1.containers”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345498567Z time=“2019-07-26T14:47:13.345465688Z” level=info msg=“loading plugin “io.containerd.grpc.v1.content”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345501912Z time=“2019-07-26T14:47:13.345480259Z” level=info msg=“loading plugin “io.containerd.grpc.v1.diff”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345528157Z time=“2019-07-26T14:47:13.345491912Z” level=info msg=“loading plugin “io.containerd.grpc.v1.events”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345538005Z time=“2019-07-26T14:47:13.345505062Z” level=info msg=“loading plugin “io.containerd.grpc.v1.healthcheck”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345542064Z time=“2019-07-26T14:47:13.345513803Z” level=info msg=“loading plugin “io.containerd.grpc.v1.images”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345549084Z time=“2019-07-26T14:47:13.345522794Z” level=info msg=“loading plugin “io.containerd.grpc.v1.leases”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345552717Z time=“2019-07-26T14:47:13.345535693Z” level=info msg=“loading plugin “io.containerd.grpc.v1.namespaces”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345572892Z time=“2019-07-26T14:47:13.345546348Z” level=info msg=“loading plugin “io.containerd.internal.v1.opt”…” type=io.containerd.internal.v1
2019-07-26T14:47:13.345767309Z time=“2019-07-26T14:47:13.345712217Z” level=info msg=“loading plugin “io.containerd.grpc.v1.snapshots”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345774236Z time=“2019-07-26T14:47:13.345726758Z” level=info msg=“loading plugin “io.containerd.grpc.v1.tasks”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345776816Z time=“2019-07-26T14:47:13.345733752Z” level=info msg=“loading plugin “io.containerd.grpc.v1.version”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345779299Z time=“2019-07-26T14:47:13.345744831Z” level=info msg=“loading plugin “io.containerd.grpc.v1.introspection”…” type=io.containerd.grpc.v1
2019-07-26T14:47:13.345936169Z time=“2019-07-26T14:47:13.345889939Z” level=info msg=serving… address="/var/run/docker/containerd/containerd-debug.sock"
2019-07-26T14:47:13.345968749Z time=“2019-07-26T14:47:13.345938412Z” level=info msg=serving… address="/var/run/docker/containerd/containerd.sock"
2019-07-26T14:47:13.345974874Z time=“2019-07-26T14:47:13.345950697Z” level=info msg=“containerd successfully booted in 0.011697s”
2019-07-26T14:47:13.353647676Z time=“2019-07-26T14:47:13.353563787Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc000612100, READY” module=grpc
2019-07-26T14:47:13.354782726Z time=“2019-07-26T14:47:13.354726699Z” level=info msg=“Setting the storage driver from the $DOCKER_DRIVER environment variable (overlay2)”
2019-07-26T14:47:13.355007770Z time=“2019-07-26T14:47:13.354940979Z” level=info msg=“parsed scheme: “unix”” module=grpc
2019-07-26T14:47:13.355016824Z time=“2019-07-26T14:47:13.354954373Z” level=info msg=“scheme “unix” not registered, fallback to default scheme” module=grpc
2019-07-26T14:47:13.355019955Z time=“2019-07-26T14:47:13.354970992Z” level=info msg=“ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0 }] }” module=grpc
2019-07-26T14:47:13.355023215Z time=“2019-07-26T14:47:13.354980102Z” level=info msg=“ClientConn switching balancer to “pick_first”” module=grpc
2019-07-26T14:47:13.355115500Z time=“2019-07-26T14:47:13.355039094Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc000612b10, CONNECTING” module=grpc
2019-07-26T14:47:13.355281569Z time=“2019-07-26T14:47:13.355223840Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc000612b10, READY” module=grpc
2019-07-26T14:47:13.355678661Z time=“2019-07-26T14:47:13.355617578Z” level=info msg=“parsed scheme: “unix”” module=grpc
2019-07-26T14:47:13.355688008Z time=“2019-07-26T14:47:13.355632747Z” level=info msg=“scheme “unix” not registered, fallback to default scheme” module=grpc
2019-07-26T14:47:13.355692262Z time=“2019-07-26T14:47:13.355649962Z” level=info msg=“ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0 }] }” module=grpc
2019-07-26T14:47:13.355705544Z time=“2019-07-26T14:47:13.355666965Z” level=info msg=“ClientConn switching balancer to “pick_first”” module=grpc
2019-07-26T14:47:13.355786860Z time=“2019-07-26T14:47:13.355724267Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc0007ba430, CONNECTING” module=grpc
2019-07-26T14:47:13.355909299Z time=“2019-07-26T14:47:13.355859676Z” level=info msg=“pickfirstBalancer: HandleSubConnStateChange: 0xc0007ba430, READY” module=grpc
2019-07-26T14:47:13.379579030Z time=“2019-07-26T14:47:13.379508204Z” level=warning msg=“Your kernel does not support swap memory limit”
2019-07-26T14:47:13.379594365Z time=“2019-07-26T14:47:13.379524896Z” level=warning msg=“Your kernel does not support cgroup rt period”
2019-07-26T14:47:13.379599132Z time=“2019-07-26T14:47:13.379529360Z” level=warning msg=“Your kernel does not support cgroup rt runtime”
2019-07-26T14:47:13.379695967Z time=“2019-07-26T14:47:13.379656961Z” level=info msg=“Loading containers: start.”
2019-07-26T14:47:13.385217590Z time=“2019-07-26T14:47:13.385133385Z” level=warning msg=“Running modprobe bridge br_netfilter failed with message: ip: can’t find device ‘bridge’\nbridge 151552 1 br_netfilter\nstp 16384 1 bridge\nllc 16384 2 bridge,stp\nip: can’t find device ‘br_netfilter’\nbr_netfilter 24576 0 \nbridge 151552 1 br_netfilter\nmodprobe: can’t change directory to ‘/lib/modules’: No such file or directory\n, error: exit status 1”
2019-07-26T14:47:13.388238949Z time=“2019-07-26T14:47:13.388166428Z” level=warning msg=“Running modprobe nf_nat failed with message: ip: can't find device 'nf_nat'\nnf_nat_masquerade_ipv4 16384 1 ipt_MASQUERADE\nnf_nat_ipv4 16384 1 iptable_nat\nnf_nat 32768 2 nf_nat_masquerade_ipv4,nf_nat_ipv4\nnf_conntrack 131072 7 ipt_MASQUERADE,nf_nat_masquerade_ipv4,nf_conntrack_netlink,nf_conntrack_ipv4,nf_nat_ipv4,xt_conntrack,nf_nat\nlibcrc32c 16384 4 xfs,nf_nat,nf_conntrack,raid456\nmodprobe: can't change directory to '/lib/modules': No such file or directory, error: exit status 1”
2019-07-26T14:47:13.391349676Z time=“2019-07-26T14:47:13.391274576Z” level=warning msg=“Running modprobe xt_conntrack failed with message: ip: can't find device 'xt_conntrack'\nxt_conntrack 16384 1 \nnf_conntrack 131072 7 ipt_MASQUERADE,nf_nat_masquerade_ipv4,nf_conntrack_netlink,nf_conntrack_ipv4,nf_nat_ipv4,xt_conntrack,nf_nat\nx_tables 40960 5 ipt_MASQUERADE,xt_addrtype,iptable_filter,xt_conntrack,ip_tables\nmodprobe: can't change directory to '/lib/modules': No such file or directory, error: exit status 1”
2019-07-26T14:47:13.604666617Z time=“2019-07-26T14:47:13.604560068Z” level=info msg=“Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address”
2019-07-26T14:47:13.802949646Z time=“2019-07-26T14:47:13.802844440Z” level=info msg=“Loading containers: done.”
2019-07-26T14:47:13.847517485Z time=“2019-07-26T14:47:13.847407634Z” level=info msg=“Docker daemon” commit=aeac9490dc graphdriver(s)=overlay2 version=19.03.0
2019-07-26T14:47:13.847548483Z time=“2019-07-26T14:47:13.847518723Z” level=info msg=“Daemon has completed initialization”
2019-07-26T14:47:13.870423129Z time=“2019-07-26T14:47:13.870318202Z” level=info msg=“API listen on [::]:2375”
2019-07-26T14:47:13.870496095Z time=“2019-07-26T14:47:13.870397324Z” level=info msg=“API listen on /var/run/docker.sock”

e[0;33m*********e[0;m

I’ve been getting the same set of warnings. Have you found a solution to get rid of the warnings?

It seems like whatever is going on truly is causing a timeout while standing up the docker:dind service. My build stage is taking about twice as long as before I started seeing these warnings.

Same problem here!

Disabling theTLS works but we’re still getting the warnings…