logzio / docker-logging-plugin

This is a docker logging driver plugin to forward docker logs to Logz.io
Apache License 2.0
7 stars 3 forks source link

failed to initialize plugin on fresh boot "resource temporarily unavailable" #30

Open alonz opened 2 years ago

alonz commented 2 years ago

Working with docker-compose and logz.io docker plugin version 1.0.2

Simple compose file for example

version: '3'

x-logging: &logzio
  driver: "logzio/logzio-logging-plugin"
  options:
    logzio-url: https://listener.logz.io:8071
    logzio-token: <mytoken>

services:
  container1:
    image: postgres:13.2
    ports: ["5432:5432/tcp"]
    logging: *logzio

  container2:
    image: postgres:13.2
    ports: ["15432:5432/tcp"]
    logging: *logzio

  container3:
    image: redis:6.2.6
    ports: ["6379:6379"]
    logging: *logzio

after restarting the docker service or after a system reboot running docker-compose up usually errors out with failed to initialize logging driver - resource temporarily unavailable

docker-compose up -d
[+] Running 2/3
 ⠿ Container compose-container3-1  Started    1.5s                                                                                                                                                                                                                                                                    
 ⠿ Container compose-container2-1  Starting   1.5s                                                                                                                                                                                                                                                                          
 ⠿ Container compose-container1-1  Started     1.5s                                                                                                                                                                                                                                                                         
Error response from daemon: failed to initialize logging driver: error creating logger: error creating logzio logger: resource temporarily unavailable

running the docker-compose up a second time will work just fine and any attempt to up/down from now on will work without any errors, that is until the next time of docker service restarts/system reboot

nothing particularly useful in the logs (including debug logs) that I could find.


#### docker logs ####

Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22Z" level=error msg="time=\"2022-04-18T09:16:22Z\" level=error msg=\"Can use only one configuration set per token: {Config:map[] ContainerID: ContainerName: ContainerEntrypoint: ContainerArgs:[] ContainerImageID: ContainerImageName: ContainerCreated:0001-01-0100:00:00 +0000 UTC ContainerEnv:[] ContainerLabels:map[] LogPath: DaemonName:}" plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22Z" level=error msg="\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22Z" level=error msg="time=\"2022-04-18T09:16:22Z\" level=error msg=\"Can use only one configuration set per token: {Config:map[] ContainerID: ContainerName: ContainerEntrypoint: ContainerArgs:[] ContainerImageID: ContainerImageName: ContainerCreated:0001-01-0100:00:00 +0000 UTC ContainerEnv:[] ContainerLabels:map[] LogPath: DaemonName:}" plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22Z" level=error msg="\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:16:22 alonz containerd: time="2022-04-18T09:16:22.766713975Z" level=info msg="starting signal loop" namespace=moby path=/run/containerd/io.containerd.runtime.v2.task/moby/2f2429b76ee34757418216e62b6092e1731a8c0460de51f710fa0609288a7541 pid=15358
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22.968407533Z" level=error msg="a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585 cleanup: failed to delete container from containerd: no such container"
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22.968536051Z" level=error msg="Handler for POST /v1.41/containers/a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585/start returned error: failed to initialize logging driver: error creating logger: error creating logzio logger: resource temporarily unavailable"
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22.978095186Z" level=error msg="5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58 cleanup: failed to delete container from containerd: no such container"
Apr 18 09:16:22 alonz dockerd: time="2022-04-18T09:16:22.979437310Z" level=error msg="Handler for POST /v1.41/containers/5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58/start returned error: failed to initialize logging driver: error creating logger: error creating logzio logger: resource temporarily unavailable"

#### docker logs with logz.io plugin in debug mode ####

Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=debug msg=\"Start logging\" file=\"/run/docker/logging/70397dfb386e0d298aebc168f9ec0525582ec0dbbe928bb95a57e51b6fc051f7\" id=5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58 logpath=\"/var/log/docker/5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=debug msg=\"Start logging\" file=\"/run/docker/logging/e900b7d201113548ec0cb6c10b0539b614d0afa4f806abdf13ec2200faa3609d\" id=a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585 logpath=\"/var/log/docker/a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=error msg=\"Can use only one configuration set per token: {Config:map[] ContainerID: ContainerName: ContainerEntrypoint: ContainerArgs:[] ContainerImageID: ContainerImageName: ContainerCreated:0001-01-0100:00:00 +0000 UTC ContainerEnv:[] ContainerLabels:map[] LogPath: DaemonName:}" plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=debug msg=\"Creating new logger for container 5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58" plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=debug msg=\"Creating new logger for container a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585" plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41Z" level=error msg="time=\"2022-04-18T09:25:41Z\" level=debug msg=\"Start logging\" file=\"/run/docker/logging/48b73042fcafc7d74fb89f9295846e3cc65d9f56fc54bf02426d65867fdc1b08\" id=2f2429b76ee34757418216e62b6092e1731a8c0460de51f710fa0609288a7541 logpath=\"/var/log/docker/2f2429b76ee34757418216e62b6092e1731a8c0460de51f710fa0609288a7541\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:41 alonz containerd: time="2022-04-18T09:25:41.092038561Z" level=info msg="starting signal loop" namespace=moby path=/run/containerd/io.containerd.runtime.v2.task/moby/5243f32e19a6ff4cd09cf2f4909a5233afd5e23c38d7a360c22997bf00fc3f58 pid=24489
Apr 18 09:25:41 alonz containerd: time="2022-04-18T09:25:41.102522402Z" level=info msg="starting signal loop" namespace=moby path=/run/containerd/io.containerd.runtime.v2.task/moby/2f2429b76ee34757418216e62b6092e1731a8c0460de51f710fa0609288a7541 pid=24506
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41.204520482Z" level=error msg="a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585 cleanup: failed to delete container from containerd: no such container"
Apr 18 09:25:41 alonz dockerd: time="2022-04-18T09:25:41.204567225Z" level=error msg="Handler for POST /v1.41/containers/a8789f20f7c51416728d111c6be29881bf788783930dea884faf0342d7a4f585/start returned error: failed to initialize logging driver: error creating logger: error creating logzio logger: resource temporarily unavailable"
Apr 18 09:25:42 alonz dockerd: time="2022-04-18T09:25:42Z" level=error msg="time=\"2022-04-18T09:25:42Z\" level=debug msg=\"Discard empty string\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d
Apr 18 09:25:42 alonz dockerd: time="2022-04-18T09:25:42Z" level=error msg="time=\"2022-04-18T09:25:42Z\" level=debug msg=\"Discard empty string\" " plugin=dc8ac7f8d2a0a0c87276f1e5ff20d3de507a37719bb66dc7458c3d1f1f21eb1d

my hunch is that it is related to the network, e.g the driver initializes before the docker network is up/running but that's just a guess nothing concreate.

mnebuerquo commented 2 years ago

I see the same issue every time I restart docker or the host.