Container not start after Host reboot (Exit code 127)

[barbuslex]

My config:

• Windows 11 x64
• WSL - Debian x64

Here my docker compose file :

  dnsmasq:
    image: dockurr/dnsmasq
    container_name: dnsmasq
    environment:
      DNS1: "1.1.1.1"
      DNS2: "1.0.0.1"
    ports:
      - 53:53/udp
      - 53:53/tcp
    cap_add:
      - NET_ADMIN
    restart: always
    volumes:
      - ./dnsmasq/etc/dnsmasq.d/:/etc/dnsmasq.d/
      - ./dnsmasq/etc/dnsmasq-hosts.conf:/etc/dnsmasq-hosts.conf
    networks:
      entrypoint:
        ipv4_address: 172.18.0.254

All works perfectly... after host reboot... the container have exit code 127 :

If i start manually the container its works.

Have you an idea how to fix it please ?

Thanks

[kroese]

Is there nothing more in the log than what is visible in the screenshot? Because I would expect some message about why it is quitting?

[barbuslex]

I have see in /var/log but the folder IS empty... Journal is it in another folder ? Le mar. 21 mai 2024, 17:10, Kroese ***@***.***> a écrit :

…

Is there nothing more in the log than what is visible in the screenshot? Because I would expect some message about why it is quitting? — Reply to this email directly, view it on GitHub <#4 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAA3TIMEAKC26TEDYAVH7ADZDNPU3AVCNFSM6AAAAABIBXPPTSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMRSHA2TMMBVGM> . You are receiving this because you authored the thread.Message ID: ***@***.***>

[kroese]

I ment the Docker log!

[barbuslex]

In docker logs there are no more than my screen shots :
docker container logs dnsmasq --details

[kroese]

I have a suspicion this Docker log is from the last time the container run (so BEFORE the reboot) and not from when it was started (AFTER the reboot).

The reason for this is that you have restart: always in your compose file. This means that when a container exits by itself, it will keep on restarting the container in a loop, until it keeps running.

But in your case that is not happening, so there seems to be a problem with Docker before it even tries to start the container. For example: if the ip/ports are already in use, or it cannot read the mount directory, it will fail to start the container, but it does not keep retrying in that case, because it was not the container that failed, but Docker itself).

Your issue seems very similar to an issue like: rancher-sandbox/rancher-desktop#4286 in which case it was also not related to the container itself.

I have no experience with Docker desktop, or where to view the general log of Docker (instead of the container log). But the quickest way to debug this issue would be to remove almost everything from the compose file (the IP adress, the ports, the volumes) and reboot the machine and see if it starts. And when it starts, slowly keep adding those lines again until it stops again on reboot. That way you at least get an idea which part of the compose file is related to the issue.

[barbuslex]

Ok... i have take docker daemon log here :

-------------------------------------------------------------------------------->8
time="2024-05-22T07:42:19.303808653Z" level=info msg="Starting up"
time="2024-05-22T07:42:19.359921407Z" level=info msg="[graphdriver] using prior storage driver: overlay2"
time="2024-05-22T07:42:19.694401787Z" level=info msg="Loading containers: start."
time="2024-05-22T07:42:19.831159396Z" level=info msg="Removing stale sandbox a37e845ff746e09cfc8982ec3b879dcc77dcfc28db32095950f4bfc6e345a3b5 (408a51e8d552c42026d4cfd442593e35a7775cad68b07698a571d4de3a0f0624)"
time="2024-05-22T07:42:19.838763625Z" level=warning msg="Failed to clean up network resources on container maildev disconnect: failed to set gateway while updating gateway: route for the gateway 172.19.0.1 could not be found: network is unreachable"
time="2024-05-22T07:42:19.843670393Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 7ee46e9cf101b1a931dcbf830536a97f6a6ee53f7c46ce44babee638c7abacf3 c0144edcf3d3d8df4abf9677551cc41c29c906d14eb1069a19222232c3686053], retrying...."
time="2024-05-22T07:42:19.851874931Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 0f8bafc6e3d9a9fdcb364b051e343df7e1a2b9fee5c90be9fc2539a0e6ef025a d0fe3e6245beeaf86c9bb37fbdbb34c9ea603aa5b358ced0b0fcbdffc39a5c6b], retrying...."
time="2024-05-22T07:42:19.856336868Z" level=info msg="Removing stale sandbox a86d09fc66a709e357fc9816a50b5119d8d28295370afdd2ac5eedae6133303a (5f072549c3e7779fccdc1fcbbcec07a293ca9a9fcc5c5af62bc6eb8a86b0cabe)"
time="2024-05-22T07:42:19.864830501Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 7ee46e9cf101b1a931dcbf830536a97f6a6ee53f7c46ce44babee638c7abacf3 15ed2e8b3fbba763e7c0af1ea36084c91e81a3b37261461d7b10df5a51d4bdde], retrying...."
time="2024-05-22T07:42:19.869109472Z" level=info msg="Removing stale sandbox faabae5311a82025b1f9a83589d39600ec6e8f7c1db94a843b36d658982d43c9 (83e6075e221b35d57574d3aab2ad54ad4db82a9ece67d67dcdc201d7690deba8)"
time="2024-05-22T07:42:19.872990252Z" level=warning msg="Failed to clean up network resources on container php55 disconnect: failed to set gateway while updating gateway: route for the gateway 172.19.0.1 could not be found: network is unreachable"
time="2024-05-22T07:42:19.877685763Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 7ee46e9cf101b1a931dcbf830536a97f6a6ee53f7c46ce44babee638c7abacf3 2ba75aeb770050944462a3129f632789d6464f452280ae50438e8e044bcb591e], retrying...."
time="2024-05-22T07:42:19.886465506Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 0f8bafc6e3d9a9fdcb364b051e343df7e1a2b9fee5c90be9fc2539a0e6ef025a 5310ab3cf5a7b9aebc9ec3b5dca3d4d96464b8922b58fade93eaca1ae50f88a2], retrying...."
time="2024-05-22T07:42:19.890942793Z" level=info msg="Removing stale sandbox 1bc6d1c019dac3a91d01979fa6286f6cf3bf6c989d213e7497f4acdceea8dfa2 (1e5ae2448c050f60314d4df952a2daba68d8c794fd1fe0cb2f8c1f778d9ee632)"
time="2024-05-22T07:42:19.902447722Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint f80731d77e30f19ce4f2388789b0180d59b40943a6dfba88e1ae2500d08c9964 4da376f8899fb446dac228f5937464a259d3bfe9fd5f17821257046bdc25b758], retrying...."
time="2024-05-22T07:42:19.906894817Z" level=info msg="Removing stale sandbox 547611f84708dc692d85d885c100acd90aae87fdfd1c7cd51e0665fa6b7a09d7 (44f9f522b840b76c54f9e8de897a4485449e95118aba6d1e8bc89942b335e7e6)"
time="2024-05-22T07:42:19.919765149Z" level=warning msg="Failed to clean up network resources on container nginxproxymanager disconnect: failed to set gateway while updating gateway: route for the gateway 172.19.0.1 could not be found: network is unreachable"
time="2024-05-22T07:42:19.924602848Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint f80731d77e30f19ce4f2388789b0180d59b40943a6dfba88e1ae2500d08c9964 87fec57c75fd79051824b4e1be830346bd61c80a41ee8fe2851db7577a0fc91b], retrying...."
time="2024-05-22T07:42:19.932617781Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 0f8bafc6e3d9a9fdcb364b051e343df7e1a2b9fee5c90be9fc2539a0e6ef025a 49c9008388fa33a9b425162b3eecf397d2d403b3d0beb90532184344291fb9a1], retrying...."
time="2024-05-22T07:42:19.936894252Z" level=info msg="Removing stale sandbox 9d5e2d9f814bf62bb3890d2fc3f0aa3d2ba06e54a683cb3bea34f95763b5bbe0 (780c263d53e50cfc27d70dd7c0dea5660b261a2a483363bbc2056b1673e0866c)"
time="2024-05-22T07:42:19.940705328Z" level=warning msg="Failed to clean up network resources on container php82 disconnect: failed to set gateway while updating gateway: route for the gateway 172.19.0.1 could not be found: network is unreachable"
time="2024-05-22T07:42:19.945437811Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 7ee46e9cf101b1a931dcbf830536a97f6a6ee53f7c46ce44babee638c7abacf3 977b628face13b2b34a13945382143a7f7947781cff67c04e2ed5192d69ef9e0], retrying...."
time="2024-05-22T07:42:19.952923733Z" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 0f8bafc6e3d9a9fdcb364b051e343df7e1a2b9fee5c90be9fc2539a0e6ef025a 3f2ecaa1523740a7b83ae17011ec4a276d958615fd107ec36b79e3bc62395e0b], retrying...."
time="2024-05-22T07:42:19.969584988Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2024-05-22T07:42:20.180761625Z" level=error msg="stream copy error: reading from a closed fifo"
time="2024-05-22T07:42:20.180761767Z" level=error msg="stream copy error: reading from a closed fifo"
time="2024-05-22T07:42:20.188655881Z" level=error msg="1e5ae2448c050f60314d4df952a2daba68d8c794fd1fe0cb2f8c1f778d9ee632 cleanup: failed to delete container from containerd: container \"1e5ae2448c050f60314d4df952a2daba68d8c794fd1fe0cb2f8c1f778d9ee632\" in namespace \"moby\": not found"
time="2024-05-22T07:42:20.928765400Z" level=error msg="stream copy error: reading from a closed fifo"
time="2024-05-22T07:42:20.928850683Z" level=error msg="stream copy error: reading from a closed fifo"
time="2024-05-22T07:42:21.677627034Z" level=error msg="failed to start container" container=1e5ae2448c050f60314d4df952a2daba68d8c794fd1fe0cb2f8c1f778d9ee632 error="failed to create task for container: failed to create shim task: OCI runtime create failed: runc create failed: unable to start container process: error during container init: error mounting \"/run/desktop/mnt/host/wsl/docker-desktop-bind-mounts/Debian/8180a849bfa4ee7b74b0b4ef8557a35fc8c707ec0d2e7af244e6c3668643806a\" to rootfs at \"/etc/dnsmasq-hosts.conf\": mount /run/desktop/mnt/host/wsl/docker-desktop-bind-mounts/Debian/8180a849bfa4ee7b74b0b4ef8557a35fc8c707ec0d2e7af244e6c3668643806a:/etc/dnsmasq-hosts.conf (via /proc/self/fd/6), flags: 0x5000: not a directory: unknown: Are you trying to mount a directory onto a file (or vice-versa)? Check if the specified host path exists and is the expected type"
time="2024-05-22T07:42:21.839189393Z" level=error msg="failed to start container" container=1172309c5b2381798be48f7d64f669d9976af9ef2abd4c26bd52a8713aa51bfe error="failed to create task for container: failed to create shim task: OCI runtime create failed: runc create failed: unable to start container process: error during container init: error mounting \"/run/desktop/mnt/host/wsl/docker-desktop-bind-mounts/Debian/0f34a228a4cf409ef06b81b212be2f5c797ccd0bbe8c7d0cb167d6add969ad92\" to rootfs at \"/root/.gitconfig\": mount /run/desktop/mnt/host/wsl/docker-desktop-bind-mounts/Debian/0f34a228a4cf409ef06b81b212be2f5c797ccd0bbe8c7d0cb167d6add969ad92:/root/.gitconfig (via /proc/self/fd/6), flags: 0x5000: not a directory: unknown: Are you trying to mount a directory onto a file (or vice-versa)? Check if the specified host path exists and is the expected type"
time="2024-05-22T07:42:22.218046970Z" level=info msg="Loading containers: done."
time="2024-05-22T07:42:22.225903759Z" level=warning msg="WARNING: No blkio throttle.read_bps_device support"
time="2024-05-22T07:42:22.225927591Z" level=warning msg="WARNING: No blkio throttle.write_bps_device support"
time="2024-05-22T07:42:22.225930895Z" level=warning msg="WARNING: No blkio throttle.read_iops_device support"
time="2024-05-22T07:42:22.225933294Z" level=warning msg="WARNING: No blkio throttle.write_iops_device support"
time="2024-05-22T07:42:22.225936207Z" level=warning msg="WARNING: daemon is not using the default seccomp profile"
time="2024-05-22T07:42:22.225947676Z" level=info msg="Docker daemon" commit=ac2de55 containerd-snapshotter=false storage-driver=overlay2 version=26.1.1
time="2024-05-22T07:42:22.226203383Z" level=info msg="Daemon has completed initialization"
time="2024-05-22T07:42:22.627591302Z" level=info msg="API listen on /var/run/docker.sock"
time="2024-05-22T07:42:22.627608075Z" level=info msg="API listen on /run/guest-services/docker.sock"
time="2024-05-22T07:42:22.633793695Z" level=error msg="Handler for GET /v1.45/services returned error: This node is not a swarm manager. Use \"docker swarm init\" or \"docker swarm join\" to connect this node to swarm and try again." spanID=43dd6cfff28241f5 traceID=f862a314e8fd9db8fa2be85f36fa36e4
2024/05/22 07:42:22 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:42:22 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-22T07:42:22.983641237Z" level=error msg="Handler for GET /v1.45/services returned error: This node is not a swarm manager. Use \"docker swarm init\" or \"docker swarm join\" to connect this node to swarm and try again." spanID=41cbf63e670495a3 traceID=994b964566726eaaa6e929092e79d6bf
time="2024-05-22T07:42:23.625824434Z" level=error msg="Handler for GET /v1.45/services returned error: This node is not a swarm manager. Use \"docker swarm init\" or \"docker swarm join\" to connect this node to swarm and try again." spanID=395d6e205884f913 traceID=b05da93237eeaf577294ce9969a93c18
time="2024-05-22T07:42:29.215860954Z" level=error msg="[resolver] failed to query external DNS server" client-addr="udp:172.18.0.253:32956" dns-server="udp:172.18.0.254:53" error="read udp 172.18.0.253:32956->172.18.0.254:53: i/o timeout" question=";ip-ranges.amazonaws.com.\tIN\t A" spanID=1da8e0592ec64ff1 traceID=98a5a293d220186c586438f8287f9b0c
2024/05/22 07:42:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:42:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:42:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-22T07:42:33.217082919Z" level=error msg="[resolver] failed to query external DNS server" client-addr="udp:172.18.0.253:54285" dns-server="udp:172.18.0.254:53" error="read udp 172.18.0.253:54285->172.18.0.254:53: i/o timeout" question=";ip-ranges.amazonaws.com.\tIN\t A" spanID=aaac436187d7a810 traceID=deee9fb571cb44a9e5f3c91239e0182b
2024/05/22 07:43:03 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:43:03 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:43:03 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:43:03 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/22 07:43:16 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)

I don't understand why it can't mount file... :S

[kroese]

I think because you use relative paths in your compose file. This means that the location will be dependant on what folder is your working directory while running compose up. When you run it manually it will be the correct folder, but when its run automaticly it will be from a different working folder.

So the solution is to use the full path in your compose, for example /mnt/c/dns/dnsmasq-hosts.conf for C:\DNS\dnsmasq-hosts.conf.

[barbuslex]

Thanks you for your help... According from daemon log file i have found theses issues :
docker/for-win#13947
docker/for-win#13985

It seems it's a docker desktop bug on windows... :S A workaround will be to start docker from scheduler task instead of docker embed settings.