Watchtower no longer working with latest Docker version?

[Altycoder]

Watchtower has been working for me for months but has suddenly stopped working, possibly after a recent Docker update, but I'm not 100% sure. My logs are now full of the following repeating messages:

time="2021-03-15T08:38:33Z" level=debug,
time="2021-03-15T08:38:33Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-15T08:38:34Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-15T08:38:34Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-15T08:38:34Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-15T11:14:16Z" level=info msg="Waiting for running update to be finished...",
time="2021-03-15T11:14:33Z" level=debug,

My config (no recent changes made):

  watchtower:
    image: containrrr/watchtower
    container_name: watchtower
    restart: unless-stopped
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
      - /etc/timezone:/etc/timezone:ro
    environment:
      - WATCHTOWER_NOTIFICATIONS=email
      - WATCHTOWER_NOTIFICATION_EMAIL_FROM=<redacted>
      - WATCHTOWER_NOTIFICATION_EMAIL_TO=<redacted>
      - WATCHTOWER_NOTIFICATION_EMAIL_SERVER=<redacted>
      - WATCHTOWER_NOTIFICATION_EMAIL_SERVER_USER=<redacted>
      - WATCHTOWER_NOTIFICATION_EMAIL_SERVER_PASSWORD=<redacted>
      - WATCHTOWER_MONITOR_ONLY=true
      - WATCHTOWER_POLL_INTERVAL=86400
      - WATCHTOWER_INCLUDE_STOPPED=true
      - WATCHTOWER_REVIVE_STOPPED=false
      - WATCHTOWER_NO_RESTART=true
      - WATCHTOWER_NO_STARTUP_MESSAGE=true
      - WATCHTOWER_CLEANUP=false
      - WATCHTOWER_DEBUG=true

Host:

• Arch x64 host runng 5.10.x LTS kernel
• Docker version: 20.10.5, build 55c4c88966

[github-actions]

Hi there! 👋🏼 As you're new to this repo, we'd like to suggest that you read our code of conduct as well as our contribution guidelines. Thanks a bunch for opening your first issue! 🙏

[piksel]

Could you elaborate on what you mean with "no longer working"?

There are no errors in the log, so I presume you experience something unexpected elsewhere?

[Altycoder]

It's no longer alerting me to new images or pulling them down like it has been for months.

Previously the log would show it searching for a new image one by one and pulling a new image if it existed then sending me an email alert. Now all I'm getting are those messages I posted for 3-4 days now and nothing else.

I've manually pulled several new images today that weren't picked up by Watchtower

[piksel]

It's a bit confusing since you turned off the startup message, but I think it looks like it's crashing?
The Sleeping for a second to ensure the docker api client has been properly initialized. is what is done on startup.
Is the whole message chain being repeated? Once per day?

[Altycoder]

Yes this exact same message block is repeated over and over as below. I will turn on startup message and restart and post back to see if that yields anything.

time="2021-03-15T08:38:33Z" level=debug,
time="2021-03-15T08:38:33Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-15T08:38:34Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-15T08:38:34Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-15T08:38:34Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-15T11:14:16Z" level=info msg="Waiting for running update to be finished...",
time="2021-03-15T11:14:33Z" level=debug,
time="2021-03-15T11:14:33Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-15T11:14:34Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-15T11:14:39Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-15T11:14:39Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-15T11:23:03Z" level=info msg="Waiting for running update to be finished...",
time="2021-03-15T11:23:20Z" level=debug,
time="2021-03-15T11:23:20Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-15T11:23:21Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-15T11:23:26Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-15T11:23:26Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-15T11:31:26Z" level=info msg="Waiting for running update to be finished...",
time="2021-03-15T11:31:44Z" level=debug,
time="2021-03-15T11:31:44Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-15T11:31:45Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-15T11:31:49Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-15T11:31:49Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-16T10:02:52Z" level=info msg="Waiting for running update to be finished...",
time="2021-03-16T10:04:03Z" level=debug,
time="2021-03-16T10:04:03Z" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized.",
time="2021-03-16T10:04:04Z" level=debug msg="Retrieving running, stopped and exited containers",
time="2021-03-16T10:04:08Z" level=debug msg="There are no additional watchtower containers",
time="2021-03-16T10:04:08Z" level=debug msg="Watchtower HTTP API skipped."

[Altycoder]

OK with the startup message on I get the following by email:

Starting Watchtower and scheduling first run: 2021-03-18 08:05:34 +0000 UTC m=+86400.870357889

Followed by the same messages above. I'm retrieving these via portainer, would there be more detailed logs I could retrieve via the container directly (and if so how)?

I have searched https://containrrr.dev/watchtower/ for the phrase "logs" but I only get one hit that's not helpful.

[lclc]

I don't know if this is related but I only saw the same output (and no updates happened) until I named all containers in my docker-compose (using container_name) and added command: --include-restarting true --interval 600 container_one container_two.

Just sharing the docker.sock didn't do the job for me.

[Altycoder]

Thanks for the reply but all the containers have "container_name" specified in my compose file and this has been working fine for a year or so and only stopped recently and the only thing that I can think of that's changed is a new version of docker, but that may be a red herring.

I've never had "command: --include-restarting true --interval 600 container_one container_two" in my config to date and I have 18 containers (incl watchtower) so not sure that's the key to this, but thanks.

I could add "WATCHTOWER_INCLUDE_RESTARTING" and "WATCHTOWER_INCLUDE_STOPPED" environment variables and recreate to see if that helps but that may not help find the root cause.

[Altycoder]

I've going to enable "WATCHTOWER_TRACE" and report back

[Altycoder]

"WATCHTOWER_TRACE=true" does not yield any more details in the logs via portainer.

[Altycoder]

Just noticed that my compose already had "WATCHTOWER_INCLUDE_STOPPED" but I've added in "WATCHTOWER_INCLUDE_RESTARTING" now as well

[Altycoder]

Looking at the docker 5.10 release notes here: https://docs.docker.com/engine/release-notes/

There is reference to two changes that may be relevant here?

docker/cli#2960
docker/cli#2987

[piksel]

Hm, no it's not once per day then. Which means that something restarts the watchtower container and on startup it schedules the next check in 24hrs, but that time will never come since the container is stopped and restarted (and the check is scheduled to 24hrs from THAT time and so on...)

time="2021-03-15T11:23:26Z" level=debug msg="Watchtower HTTP API skipped.",
time="2021-03-15T11:31:26Z" level=info msg="Waiting for running update to be finished...",

So it recieves a SIGINT/SIGTERM ~10 minutes after starting... Something is telling docker to stop the container... 🤷‍♀️

[Altycoder]

Have you reviewed the two changes to docker 5.10 that I posted above? I don't know enough about this but there is talk in one of these about catching signals etc

docker/cli#2960
docker/cli#2987

[piksel]

Yeah, I saw that. Not something that seems obvious to cause this. Why are you saying 5.10 btw? I assume you mean v20.10.5 ?

[Altycoder]

Sorry yes Docker v20.10.5

[Altycoder]

This seems to have somehow rectified itself. What ever was broken must have been updated towards the end of last week....?

There were no docker/docker-compose updates last week so this is a mystery...

[ghost]

To avoid important communication to get lost in a closed issues no one monitors, I'll go ahead and lock this issue. If you want to continue the discussion, please open a new issue. Thank you! 🙏🏼