Service probably didn't start properly

[julesbonnard]

Hi,
I encounter a problem today with my Gitlab CI with docker-in-docker, in which I use the docker image lordgaav/dind-options:latest.

Running with gitlab-runner 10.3.0 (5cf5e19a)
  on Docker-in-docker Runner (324fb482)
Using Docker executor with image docker:latest ...
Starting service lordgaav/dind-options:latest ...
Pulling docker image lordgaav/dind-options:latest ...
Using docker image lordgaav/dind-options:latest ID=sha256:2208fa579d48c068e145a56c841db351b09fa8bcfabff06b88f9530689ef7214 for lordgaav/dind-options service...
Waiting for services to be up and running...

*** WARNING: Service runner-324fb482-project-159-concurrent-0-lordgaav__dind-options-0 probably didn't start properly.

Error response from daemon: Cannot link to a non running container: /runner-324fb482-project-159-concurrent-0-lordgaav__dind-options-0 AS /runner-324fb482-project-159-concurrent-0-lordgaav__dind-options-0-wait-for-service/runner-324fb482-project-159-concurrent-0-lordgaav__dind-options-0

2018-01-05T12:55:41.325634773Z time="2018-01-05T12:55:41.324845230Z" level=warning msg="could not change group /var/run/docker.sock to docker: group docker not found"
2018-01-05T12:55:41.325712467Z time="2018-01-05T12:55:41.325469290Z" level=warning msg="[!] DON'T BIND ON ANY IP ADDRESS WITHOUT setting --tlsverify IF YOU DON'T KNOW WHAT YOU'RE DOING [!]"
2018-01-05T12:55:41.332496968Z time="2018-01-05T12:55:41.331869526Z" level=info msg="libcontainerd: started new docker-containerd process" pid=17
2018-01-05T12:55:41.348990341Z time="2018-01-05T12:55:41Z" level=info msg="starting containerd" module=containerd revision=89623f28b87a6004d4b785663257362d1658a729 version=v1.0.0 
2018-01-05T12:55:41.349023556Z time="2018-01-05T12:55:41Z" level=info msg="setting subreaper..." module=containerd 
2018-01-05T12:55:41.349029020Z time="2018-01-05T12:55:41Z" level=info msg="changing OOM score to -500" module=containerd 
2018-01-05T12:55:41.349033473Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.content.v1.content"..." module=containerd type=io.containerd.content.v1 
2018-01-05T12:55:41.349038126Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.btrfs"..." module=containerd type=io.containerd.snapshotter.v1 
2018-01-05T12:55:41.349042601Z time="2018-01-05T12:55:41Z" 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" module=containerd 
2018-01-05T12:55:41.349054606Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.snapshotter.v1.overlayfs"..." module=containerd type=io.containerd.snapshotter.v1 
2018-01-05T12:55:41.349059098Z time="2018-01-05T12:55:41Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.overlayfs" error="/var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.overlayfs does not support d_type. If the backing filesystem is xfs, please reformat with ftype=1 to enable d_type support" module=containerd 
2018-01-05T12:55:41.349064646Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.metadata.v1.bolt"..." module=containerd type=io.containerd.metadata.v1 
2018-01-05T12:55:41.349068986Z time="2018-01-05T12:55:41Z" level=warning msg="could not use snapshotter overlayfs in metadata plugin" error="/var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.overlayfs does not support d_type. If the backing filesystem is xfs, please reformat with ftype=1 to enable d_type support" module="containerd/io.containerd.metadata.v1.bolt" 
2018-01-05T12:55:41.349075487Z time="2018-01-05T12:55:41Z" 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" module="containerd/io.containerd.metadata.v1.bolt" 
2018-01-05T12:55:41.354438408Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.differ.v1.walking"..." module=containerd type=io.containerd.differ.v1 
2018-01-05T12:55:41.354455235Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.gc.v1.scheduler"..." module=containerd type=io.containerd.gc.v1 
2018-01-05T12:55:41.354460672Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.containers"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354484392Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.content"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354490278Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.diff"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354494726Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.events"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354499150Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.healthcheck"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354503625Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.images"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354507873Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.leases"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354511836Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.namespaces"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354516097Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.snapshots"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.354520276Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.monitor.v1.cgroups"..." module=containerd type=io.containerd.monitor.v1 
2018-01-05T12:55:41.355034938Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.runtime.v1.linux"..." module=containerd type=io.containerd.runtime.v1 
2018-01-05T12:55:41.370257155Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.tasks"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.370294673Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.version"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.370300283Z time="2018-01-05T12:55:41Z" level=info msg="loading plugin "io.containerd.grpc.v1.introspection"..." module=containerd type=io.containerd.grpc.v1 
2018-01-05T12:55:41.370304964Z time="2018-01-05T12:55:41Z" level=info msg=serving... address="/var/run/docker/containerd/docker-containerd-debug.sock" module="containerd/debug" 
2018-01-05T12:55:41.370309623Z time="2018-01-05T12:55:41Z" level=info msg=serving... address="/var/run/docker/containerd/docker-containerd.sock" module="containerd/grpc" 
2018-01-05T12:55:41.370313974Z time="2018-01-05T12:55:41Z" level=info msg="containerd successfully booted in 0.021299s" module=containerd 
2018-01-05T12:55:41.378230532Z time="2018-01-05T12:55:41.377760763Z" level=info msg="Setting the storage driver from the $DOCKER_DRIVER environment variable (overlay)"
2018-01-05T12:55:41.388325258Z Error starting daemon: error initializing graphdriver: overlay: the backing xfs filesystem is formatted without d_type support, which leads to incorrect behavior. Reformat the filesystem with ftype=1 to enable d_type support. Backing filesystems without d_type support are not supported.

*********

Using docker image sha256:b7b43c13f039d3e50edcafa31fd1f2cc2a2863edaf97decd341371823636e72b for predefined container...
Pulling docker image docker:latest ...
Using docker image docker:latest ID=sha256:337682841fd659abf68e069a9ec34e8148df829a8c227e761ad938edc342c9ab for build container...
Running on runner-324fb482-project-159-concurrent-0 via cdafe38b28db...
Cloning repository...
Cloning into '/builds/toolkit/toolkit-ui'...
Checking out 765a0834 as dev...
Skipping Git submodules setup
$ docker info
error during connect: Get http://lordgaav__dind-options:2375/v1.35/info: dial tcp: lookup lordgaav__dind-options on 158.50.0.1:53: no such host
ERROR: Job failed: exit code 1

Yesterday, the same build succeed with this log :

Running with gitlab-runner 10.3.0 (5cf5e19a)
  on Docker-in-docker Runner (324fb482)
Using Docker executor with image docker:latest ...
Starting service lordgaav/dind-options:latest ...
Pulling docker image lordgaav/dind-options:latest ...
Using docker image lordgaav/dind-options:latest ID=sha256:fdc02130c7b38ed326f25404feda086566eed4f6b6e5a07d14c3366e78483167 for lordgaav/dind-options service...
Waiting for services to be up and running...
Using docker image sha256:a3972f7ab25cf40dcce704a7d73d0d41558f95b9ce8ab563b52cae36fe7ff3b5 for predefined container...
Pulling docker image docker:latest ...
Using docker image docker:latest ID=sha256:337682841fd659abf68e069a9ec34e8148df829a8c227e761ad938edc342c9ab for build container...
Running on runner-324fb482-project-159-concurrent-0 via ddda0a9cdf85...
Cloning repository...
Cloning into '/builds/toolkit/toolkit-ui'...
Checking out 7bff42c4 as dev...
Skipping Git submodules setup
$ docker info
Containers: 0
 Running: 0
 Paused: 0
 Stopped: 0
Images: 0
Server Version: 17.10.0-ce
Storage Driver: overlay
 Backing Filesystem: xfs
 Supports d_type: false
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 06b9cb35161009dcb7123345749fef02f7cea8e0
runc version: 0351df1c5a66838d0c392b4ac4cf9450de844e2d
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 3.10.0-327.el7.x86_64
Operating System: Alpine Linux v3.6 (containerized)
OSType: linux
Architecture: x86_64
CPUs: 2
Total Memory: 3.703GiB
Name: 240cb45f5ceb
ID: NYAB:FJPQ:BPLF:SPEY:REZP:ZHHR:LOB5:GLPV:UA7H:QNUD:UROV:25TI
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 infodyn-gitlab.afp.com:4567
 127.0.0.0/8
Live Restore Enabled: false

WARNING: overlay: the backing xfs filesystem is formatted without d_type support, which leads to incorrect behavior.
         Reformat the filesystem with ftype=1 to enable d_type support.
         Running without d_type support will not be supported in future releases.
WARNING: bridge-nf-call-iptables is disabled
WARNING: bridge-nf-call-ip6tables is disabled
...

It appears that you rebuild the image during the day -> https://hub.docker.com/r/lordgaav/dind-options/builds/

What changes did you make ? Could it be related to the error ?

Thanks in advance,

[LordGaav]

I haven't made any changes in a while. However, the image is rebuilt when the source Docker repo changes, any changes in the Docker image repo triggers a rebuild of my image. Looking at their repo, the change they made yesterday was uploading a rc version of Docker. The last relevant change for my image was nine days ago: https://github.com/docker-library/docker/commits/master .

I'm curious about this entry:

2018-01-05T12:55:41.388325258Z Error starting daemon: error initializing graphdriver: overlay: the backing xfs filesystem is formatted without d_type support, which leads to incorrect behavior. Reformat the filesystem with ftype=1 to enable d_type support. Backing filesystems without d_type support are not supported.

It seems your filesystem is XFS? I don't have much experience with that, but it seems the direct cause.

[julesbonnard]

Thanks for your answer.
I understand it's not due to any change in your image. It's strange because I didn't change anything during the night, but anyway, I will try to fix the filesystem.
Best

[Hugo1380]

Same issue here, do you have an idea to fix it ?

[LordGaav]

The issue is caused by the fact that the upstream Dockerfile mentions two ports, and the Gitlab health checker picks the first (which is wrong). There seems to be a lot of discussion about improving that feature in Gitlab, but until then it's safe to ignore the errors (albeit somewhat annoying).

https://gitlab.com/gitlab-org/gitlab-runner/-/issues/3984