:latest-dev fails on image updates and is removing containers

[ilike2burnthing]

Describe the bug

Following #1800 and #1801 being merged, :latest-dev is failing on image updates, resulting in containers being removed without being replaced.

Likely related, when Watchtower updated itself it (presumably) failed repeatedly for hours, resulting in 96 copies of the Watchtower container being made, CPU usage being pinned to 99%, and my NAS becoming unresponsive. I (eventually) stopped all containers, removed the duplicates, started my normal containers again, and pulled a new Watchtower image. The issue didn't reoccur, so I put it down to a corrupted update or temporary issue on my end. However, since then 4 containers have been removed, with related errors in Watchtower's logs.

Steps to reproduce

1. using :latest-dev container
2. not sure if necessary, but the ENVs WATCHTOWER_CLEANUP, WATCHTOWER_INCLUDE_RESTARTING, and WATCHTOWER_INCLUDE_STOPPED were set to true
3. Watchtower updates images
4. containers will be removed, new and old images are both present, errors appear in Watchtower's logs

Expected behavior

Updates behave normally.

Screenshots

No response

Environment

• Platform: Linux Asustor-NAS 5.13.x # 1 SMP Fri Sep 8 00:15:30 CST 2023 x86_64 GNU/Linux
• Docker Version: 23.0.6

Your logs

time="2023-10-22T02:35:42Z" level=info msg="Found new docker.io/linuxserver/radarr:nightly image (1b6ba5e36bb6)"
time="2023-10-22T02:35:51Z" level=info msg="Stopping /Radarr (75034119a69c) with SIGTERM"
2023/10/22 02:35:56 cron: panic running job: runtime error: invalid memory address or nil pointer dereference
goroutine 6326 [running]:
github.com/robfig/cron.(*Cron).runWithRecovery.func1()
	/go/pkg/mod/github.com/robfig/cron@v1.2.0/cron.go:161 +0x65
panic({0xa9dc80?, 0x10e3dd0?})
	/usr/local/go/src/runtime/panic.go:914 +0x21f
github.com/containrrr/watchtower/pkg/container.Container.GetCreateConfig({0x80?, 0x6d?, 0xc0002118c0?, 0xc0002d0b00?})
	/go/watchtower/pkg/container/container.go:308 +0x31f
github.com/containrrr/watchtower/pkg/container.dockerClient.StartContainer({{0xc82218, 0xc0002b6300}, {0x1, 0x0, 0x1, 0x0, 0x1, {0x0, 0x0}}}, {0xc7f1f8, ...})
	/go/watchtower/pkg/container/client.go:251 +0x95
github.com/containrrr/watchtower/internal/actions.restartStaleContainer({0xc7f1f8, 0xc000480ff0}, {0xc79f68, 0xc000286840}, {0xc0002916d0, 0x1, 0x0, 0x2540be400, 0x0, 0x0, ...})
	/go/watchtower/internal/actions/update.go:224 +0xec
github.com/containrrr/watchtower/internal/actions.restartContainersInSortedOrder({0xc0002aeb00, 0xb, 0xc000387cf8?}, {0xc79f68, 0xc000286840}, {0xc0002916d0, 0x1, 0x0, 0x2540be400, 0x0, ...}, ...)
	/go/watchtower/internal/actions/update.go:184 +0x1a8
github.com/containrrr/watchtower/internal/actions.Update({0xc79f68, 0xc000286840}, {0xc0002916d0, 0x1, 0x0, 0x2540be400, 0x0, 0x0, 0x0, 0x0, ...})
	/go/watchtower/internal/actions/update.go:87 +0xa1f
github.com/containrrr/watchtower/cmd.runUpdatesWithNotifications(0xc0002916d0)
	/go/watchtower/cmd/root.go:371 +0xde
github.com/containrrr/watchtower/cmd.runUpgradesOnSchedule.func1()
	/go/watchtower/cmd/root.go:325 +0xc6
github.com/robfig/cron.FuncJob.Run(0xc00028aa80?)
	/go/pkg/mod/github.com/robfig/cron@v1.2.0/cron.go:92 +0x12
github.com/robfig/cron.(*Cron).runWithRecovery(0x57c0cf?, {0xc6fae0?, 0xc00029b000?})
	/go/pkg/mod/github.com/robfig/cron@v1.2.0/cron.go:165 +0x53
created by github.com/robfig/cron.(*Cron).run in goroutine 20
	/go/pkg/mod/github.com/robfig/cron@v1.2.0/cron.go:199 +0x779

Additional context

Apologies for the lack of debug logs, I don't really want to try to repeat this.

[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! 🙏

[spupuz]

Same problem for me

[ilike2burnthing]

@spupuz were you using any of the ENVs mentioned in step 2 above?

Please provide your environment information as above (may not be necessary, but might as well while waiting).

[spupuz]

  - WATCHTOWER_REVIVE_STOPPED=true
  - WATCHTOWER_POLL_INTERVAL=7200
  - WATCHTOWER_ROLLING_RESTART=false
  - WATCHTOWER_DEBUG=true
  - WATCHTOWER_INCLUDE_RESTARTING=true
  - WATCHTOWER_CLEANUP=true
  - WATCHTOWER_INCLUDE_STOPPED=true
  - WATCHTOWER_LOG_LEVEL=debug
  - WATCHTOWER_NOTIFICATIONS=shoutrrr

[piksel]

Thanks for reporting this! This was just me not testing "unaffected" containers (and forgetting that everything can be nil in the configs).

[spupuz]

also this morning got 2 installation with different container update but not recreated

[ilike2burnthing]

Ta, working.

[ilike2burnthing]

Spoke too soon. The first part was resolved, other containers are no longer being removed on update, but I have 93 duplicate Watchtower containers as a result of the failed Watchtower updates:

time="2023-10-23T21:30:11Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (5012ce7beb41)"
time="2023-10-23T21:30:19Z" level=info msg="Creating /Watchtower"
time="2023-10-23T21:30:20Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:30:20Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:30:20Z" level=info msg="Session done" Failed=0 Scanned=11 Updated=1 notify=no
time="2023-10-23T21:35:08Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (5012ce7beb41)"
time="2023-10-23T21:35:16Z" level=info msg="Creating /dEocsAqHFFYeNOjRJtUKTfDuoJqZhPeP"
time="2023-10-23T21:35:17Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:35:17Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:35:17Z" level=info msg="Session done" Failed=0 Scanned=12 Updated=1 notify=no
time="2023-10-23T21:40:16Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:40:22Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:40:24Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:40:28Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:40:36Z" level=info msg="Creating /gJAjvTqcukdnlKetuzxsdCMAazTUkFBX"
time="2023-10-23T21:40:38Z" level=info msg="Creating /dEocsAqHFFYeNOjRJtUKTfDuoJqZhPeP"
time="2023-10-23T21:40:40Z" level=info msg="Creating /Watchtower"
time="2023-10-23T21:40:40Z" level=error msg="Error response from daemon: Conflict. The container name \"/Watchtower\" is already in use by container \"a5801b6d5548e176bec05c6157325f3b1cbc259ff472231a0c51182e65414754\". You have to remove (or rename) that container to be able to reuse that name."
time="2023-10-23T21:40:40Z" level=info msg="Creating /yFEZvkPkMSxgEheipQVoBIUHPQimWUUd"
time="2023-10-23T21:40:41Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:40:41Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:40:41Z" level=info msg="Removing image 5012ce7beb41"
time="2023-10-23T21:40:41Z" level=error msg="Error response from daemon: conflict: unable to delete 5012ce7beb41 (cannot be forced) - image is being used by running container ec05547b3bf2"
time="2023-10-23T21:40:41Z" level=info msg="Session done" Failed=1 Scanned=14 Updated=3 notify=no
time="2023-10-23T21:45:11Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:45:13Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:45:15Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:45:19Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:45:27Z" level=info msg="Creating /vnxLoJDIxQUGtLuMhUODdufjTuvoGarl"
time="2023-10-23T21:45:28Z" level=info msg="Creating /HhoHxESretdhGuLOLUkkuXuNNHabVVia"
time="2023-10-23T21:45:30Z" level=info msg="Creating /zRVdXiEwiKafvocdUVNDuKICFJjdLXZa"
time="2023-10-23T21:45:31Z" level=info msg="Creating /eDQJkNpIWCKZMKOQFhkewHMxeolMGWlW"
time="2023-10-23T21:45:33Z" level=info msg="Removing image 5012ce7beb41"
time="2023-10-23T21:45:33Z" level=error msg="Error response from daemon: conflict: unable to delete 5012ce7beb41 (cannot be forced) - image is being used by running container ec05547b3bf2"
time="2023-10-23T21:45:33Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:45:33Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:45:33Z" level=info msg="Session done" Failed=0 Scanned=20 Updated=4 notify=no
time="2023-10-23T21:50:26Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:50:28Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:50:30Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:50:34Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:50:42Z" level=info msg="Creating /poXbDFWEoVfIBuQgDezvqVhyOGkarMya"
time="2023-10-23T21:50:44Z" level=info msg="Creating /aHsmHVPKlQXbGddcDumkztPkCiJKpdeV"
time="2023-10-23T21:50:46Z" level=info msg="Creating /xpifNajsWTfKVEdTUqBCVYoBoMUfidei"
time="2023-10-23T21:50:48Z" level=info msg="Creating /omSjRTHwHQXCSWpvQeeqYGcszUMsfEqt"
time="2023-10-23T21:50:50Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:50:50Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:50:50Z" level=info msg="Removing image 5012ce7beb41"
time="2023-10-23T21:50:50Z" level=error msg="Error response from daemon: conflict: unable to delete 5012ce7beb41 (cannot be forced) - image is being used by running container ec05547b3bf2"
time="2023-10-23T21:50:50Z" level=info msg="Session done" Failed=0 Scanned=36 Updated=4 notify=no
time="2023-10-23T21:55:56Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:55:58Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:56:01Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:56:05Z" level=info msg="Found new docker.io/containrrr/watchtower:latest-dev image (0c541998e62a)"
time="2023-10-23T21:56:13Z" level=info msg="Creating /GXIWcKKfkaaQhjRNhThIklNijJWdddvz"
time="2023-10-23T21:56:16Z" level=info msg="Creating /iJuttJPRmcaMbvCEmiohhLCQCssYUsNS"
time="2023-10-23T21:56:20Z" level=info msg="Creating /EZOdsUYfXcYEXUdyPSYpCvxvtUrJVVlU"
time="2023-10-23T21:56:25Z" level=info msg="Creating /SyLgoMmpESGNvHPWNnGzuEVUEvYfBgUX"
time="2023-10-23T21:56:32Z" level=info msg="Removing image 90520496a90c"
time="2023-10-23T21:56:32Z" level=error msg="Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd"
time="2023-10-23T21:56:32Z" level=info msg="Removing image 5012ce7beb41"
time="2023-10-23T21:56:32Z" level=error msg="Error response from daemon: conflict: unable to delete 5012ce7beb41 (cannot be forced) - image is being used by running container c4c61a4b1691"
time="2023-10-23T21:56:32Z" level=info msg="Session done" Failed=0 Scanned=66 Updated=4 notify=no
time="2023-10-23T22:04:08Z" level=warning msg="Could not do a head request for \"docker.io/containrrr/watchtower:latest-dev\", falling back to regular pull." container=/RReBKOsYmJvTZtkUlnCMGvsehAMpUHdS image="docker.io/containrrr/watchtower:latest-dev"
time="2023-10-23T22:04:11Z" level=warning msg="Reason: Get \"https://auth.docker.io/token?scope=repository%3Acontainrrr%2Fwatchtower%3Apull&service=registry.docker.io\": net/http: TLS handshake timeout" container=/RReBKOsYmJvTZtkUlnCMGvsehAMpUHdS image="docker.io/containrrr/watchtower:latest-dev"
time="2023-10-23T22:08:16Z" level=warning msg="Could not do a head request for \"docker.io/containrrr/watchtower:latest-dev\", falling back to regular pull." container=/OHMwCQPqYmByzteSbyJWoYtkarNMqiee image="docker.io/containrrr/watchtower:latest-dev"
time="2023-10-23T22:08:18Z" level=warning msg="Reason: Get \"https://index.docker.io/v2/\": net/http: TLS handshake timeout" container=/OHMwCQPqYmByzteSbyJWoYtkarNMqiee image="docker.io/containrrr/watchtower:latest-dev"
time="2023-10-23T22:14:23Z" level=info msg="Waiting for running update to be finished..."

[piksel]

Are you saying that it keeps spawning new ones?

[ilike2burnthing]

Yes. From the logs it seems that the old container isn't stopped, so can't be removed.

[NonaSuomy]

time="2023-11-02T16:00:39-04:00" level=debug msg="Sleeping for a second to ensure the docker api client has been properly initialized."
time="2023-11-02T16:00:40-04:00" level=debug msg="Making sure everything is sane before starting"
time="2023-11-02T16:00:40-04:00" level=debug msg="Retrieving running containers"
time="2023-11-02T16:00:40-04:00" level=debug msg="There are no additional watchtower containers"
time="2023-11-02T16:00:40-04:00" level=debug msg="Watchtower HTTP API skipped."
time="2023-11-02T16:00:40-04:00" level=info msg="Watchtower v1.6.0-15-g887569f"
time="2023-11-02T16:00:40-04:00" level=info msg="Using notifications: discord, smtp"
time="2023-11-02T16:00:40-04:00" level=info msg="Only checking containers using enable label"
time="2023-11-02T16:00:40-04:00" level=info msg="Scheduling first run: 2023-11-03 16:00:00 -0400 EDT"
time="2023-11-02T16:00:40-04:00" level=info msg="Note that the first check will be performed in 23 hours, 59 minutes, 19 seconds"

time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /HOMFsEWFIzsOgmWUONtOZKMTSuYxsfeL"
time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /dpiMbTJwmjVRlJYaJOaLPTTJxpOhNtFp"
time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /watchtower"
time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /jMXWFPOQcrAWYNKUHqsbphwlvmtNlkbT"
time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /EBeqpVmhSAEOJYfCvnwZHrRPmuWIVLdZ"
time="2023-11-02T16:03:07-04:00" level=debug msg="This is the watchtower container /SNqZDrjmuWWOpdCyvNDPWSVMDsLsqlFc"
time="2023-11-02T16:03:07-04:00" level=info msg="Stopping /esphome (b4eef301d923) with SIGTERM"
time="2023-11-02T16:03:07-04:00" level=error msg="Error response from daemon: Cannot kill container: b4eef301d9239721e4bbc4d4392854c73d9222b542b324f087e1a1aab31ab8c7: No such container: b4eef301d9239721e4bbc4d4392854c73d9222b542b324f087e1a1aab31ab8c7"
time="2023-11-02T16:03:07-04:00" level=debug msg="Renaming container /dpiMbTJwmjVRlJYaJOaLPTTJxpOhNtFp (d7e1b475f3c6) to IhFVxNaQalsqZVAisoJOPeppfIqdANqP"
time="2023-11-02T16:03:07-04:00" level=info msg="Creating /dpiMbTJwmjVRlJYaJOaLPTTJxpOhNtFp"
time="2023-11-02T16:03:07-04:00" level=error msg="Error response from daemon: Conflict. The container name \"/dpiMbTJwmjVRlJYaJOaLPTTJxpOhNtFp\" is already in use by container \"59cdf37cbd7307c0642ee5eb65ea0b0d13d1a34286fa3b7a9fde894b10eda242\". You have to remove (or rename) that container to be able to reuse that name."
time="2023-11-02T16:03:07-04:00" level=debug msg="Renaming container /HOMFsEWFIzsOgmWUONtOZKMTSuYxsfeL (de15d13c0ce2) to QYHEzfpTAXyQxPMcyehYbJkeMkHJecPm"
time="2023-11-02T16:03:07-04:00" level=info msg="Creating /HOMFsEWFIzsOgmWUONtOZKMTSuYxsfeL"
time="2023-11-02T16:03:07-04:00" level=error msg="Error response from daemon: Conflict. The container name \"/HOMFsEWFIzsOgmWUONtOZKMTSuYxsfeL\" is already in use by container \"0558ea1d203f60d8b05c55f9bd706af674be1e65532ab5f875ee165ae9ac21ea\". You have to remove (or rename) that container to be able to reuse that name."
time="2023-11-02T16:03:07-04:00" level=info msg="Session done" Failed=3 Scanned=19 Updated=0 notify=no
time="2023-11-02T16:03:07-04:00" level=debug msg="Scheduled next run: 2023-11-03 16:00:00 -0400 EDT"

[piksel]

@ilike2burnthing You said that

I (eventually) stopped all containers, removed the duplicates, started my normal containers again

Did that not include the watchtower instances? As long as you have the old broken one it might continue to misbehave, although it should be removed by the new watchtower instance.

Looking at @NonaSuomy s logs it seems like the "random" names are not so random and it conflicts with an old failed update... Perhaps we can fix it by altering the random name algorithm...

If you want to just fix your installs right now, just remove all watchtower instances and create a new one with the current :latest-dev image.

[ilike2burnthing]

The only duplicates were Watchtower containers, so yes I removed all of them.

The two main error messages from my logs above were:

Error response from daemon: conflict: unable to delete 90520496a90c (cannot be forced) - image is being used by running container b54aebf309bd

and

Error response from daemon: Conflict. The container name "/Watchtower" is already in use by container "a5801b6d5548e176bec05c6157325f3b1cbc259ff472231a0c51182e65414754". You have to remove (or rename) that container to be able to reuse that name.

The other containers' logs showed errors that their container names were also in use.

The Watchtower container is set to always restart, not sure if this is causing an issue, but it's previously been fine.

[NonaSuomy]

On your last note mine are all set to restart: no as it conflicts with my docker-net-DHCP plugin causing them to all lock up at boot because of a bug in their code base.
When I first got this issue I deleted all the containers but left the last one named watchtower without a random name but it seemed to have a current update date. They then came back and I posted the above results. I will try deleting them all and hope for the best.