Allow using stdout for session results to be used in scripts

[Antiz96]

Quick intro

Hi, I realize that it might actually be the intended behavior and thus that it should not be considered as a bug. If that's the case, I'm sorry and this issue could be closed :smile:
However, if that's the intended behavior, I think there could be a debate about it (that could lead to a feature request). I gave more information about that in the "additional context" section.
Anyway, thanks for your awesome work !

Describe the bug

The regular info messages shown below are written to standard error (stderr) instead of standard output (stdout) when using watchtower with the "run once" mode, even tho the command exits with a 0 return code (command used : sudo docker run --rm -v /var/run/docker.sock:/var/run/docker.sock containrrr/watchtower --cleanup --run-once) :

time="2022-07-31T21:55:59Z" level=info msg="Watchtower 1.4.0"
time="2022-07-31T21:55:59Z" level=info msg="Using no notifications"
time="2022-07-31T21:55:59Z" level=info msg="Checking all containers (except explicitly disabled with label)"
time="2022-07-31T21:55:59Z" level=info msg="Running a one time update."
time="2022-07-31T21:56:02Z" level=info msg="Session done" Failed=0 Scanned=3 Updated=0 notify=no
time="2022-07-31T21:56:02Z" level=info msg="Waiting for the notification goroutine to finish" notify=no

To Reproduce

Run the command and echo the return code shows 0 (which is expected) :
sudo docker run --rm -v /var/run/docker.sock:/var/run/docker.sock containrrr/watchtower --cleanup --run-once ; echo $?

time="2022-07-31T21:59:47Z" level=info msg="Watchtower 1.4.0"
time="2022-07-31T21:59:47Z" level=info msg="Using no notifications"
time="2022-07-31T21:59:47Z" level=info msg="Checking all containers (except explicitly disabled with label)"
time="2022-07-31T21:59:47Z" level=info msg="Running a one time update."
time="2022-07-31T21:59:50Z" level=info msg="Session done" Failed=0 Scanned=3 Updated=0 notify=no
time="2022-07-31T21:59:50Z" level=info msg="Waiting for the notification goroutine to finish" notify=no
0

However, redirecting standard output to "/dev/null" (or into a file) does nothing :
sudo docker run --rm -v /var/run/docker.sock:/var/run/docker.sock containrrr/watchtower --cleanup --run-once > /dev/null

time="2022-07-31T22:02:51Z" level=info msg="Watchtower 1.4.0"
time="2022-07-31T22:02:51Z" level=info msg="Using no notifications"
time="2022-07-31T22:02:51Z" level=info msg="Checking all containers (except explicitly disabled with label)"
time="2022-07-31T22:02:51Z" level=info msg="Running a one time update."
time="2022-07-31T22:02:54Z" level=info msg="Session done" Failed=0 Scanned=3 Updated=0 notify=no
time="2022-07-31T22:02:54Z" level=info msg="Waiting for the notification goroutine to finish" notify=no

While redirecting standard error to "/dev/null" (or into a file) does redirect the ouput : sudo docker run --rm -v /var/run/docker.sock:/var/run/docker.sock containrrr/watchtower --cleanup --run-once 2> /dev/null --> gives no output

sudo docker run --rm -v /var/run/docker.sock:/var/run/docker.sock containrrr/watchtower --cleanup --run-once 2> test.txt ; cat test.txt

time="2022-07-31T22:07:40Z" level=info msg="Watchtower 1.4.0"
time="2022-07-31T22:07:40Z" level=info msg="Using no notifications"
time="2022-07-31T22:07:40Z" level=info msg="Checking all containers (except explicitly disabled with label)"
time="2022-07-31T22:07:40Z" level=info msg="Running a one time update."
time="2022-07-31T22:07:43Z" level=info msg="Session done" Failed=0 Scanned=3 Updated=0 notify=no
time="2022-07-31T22:07:43Z" level=info msg="Waiting for the notification goroutine to finish" notify=no

This behavior also happens if a container gets updated (at first I was wondering if those messages were designed to go to standard error if no update were available).

Expected behavior

I expected those info messages to be written in standard output and not standard error. If those info messages are meant to be written in standard error, I may have a suggestion (see the "Additional context" section).

Environment

Tested on 2 different environment (same result for both)

Environment 1

• Debian 11 installed directly on hardware
• X86_64
• Docker version 20.10.17, build 100c701

Environment 2

• Arch Linux VM installed on Proxmox
• X86_64
• Docker version 20.10.17, build 100c70180f

Additional context

As I said in the introduction, I initially thought it was a bug but then realized it could actually be the intended behavior (I'm sorry if that's the case).
I understand that there's no real/standard convention about redirecting logging outputs to stdout or stderr, both are acceptable specially when a command doesn't have a "regular output" like it's the case here. However, these info messages contain a crucial information (at least to me) : The name of container that got updated.

Here's my situation (to illustrate my point) :
I'm not a fan of automatic updates processes. However, I like to simplify them as much as possible, (especially since I have a lot of servers that run docker containers). This is where the watchtower's run once mode becomes handy.
So, to simplify my docker containers update process, I wrote an ansible playbook that launches watchtower with the run once mode on every of my servers, which I launch manually and regularly. To be able to see which containers got updated by watchtower (in order to know which ones need to be tested afterward to validate the update), I asked the playbook to redirect the standard output of the watchtower command to its own output. This is how I saw that the standard output of Watchtower does not contains info messages and thus the name of the container(s) that got updated.
Of course, redirecting standard error of the Watchtower command instead of standard output in the ansible playbook (or redirecting stderr in stdout in the command) does work, but it feels a little weird to have to redirect stderr to get a standard information such as the name of containers.

According to that, here's my thought about this :

• If the info messages were not specifically meant to be written in the stderr, then I guess this bug report is legit.
• If the info messages were indeed meant to be written in the stderr, I would suggest a feature request that does output the name of the container(s) that got updated in the stdout. So people like me that use watchtower with the run once mode inside a script or an ansible playbook (for instance) doesn't have to redirect stderr to get this information (which is crucial for me). One could argue that people using watchtower directly as a command on their machines (and not inside an ansible playbook like I do) would then get the name of updated container(s) twice as both stdout and stderr are shown by default when launching a command. But I still think that a dedicated line that gives the name of container(s) that got updated once treatments are finished would be useful and more easily readable then retrieving those names in the info logs messages in the form of Stopping /container_name (container_id) with SIGTERM\, Creating /container_name\, etc... Especially if you have servers that host a lot of docker containers.

I know my case may be a bit particular but I think this would also benefits people that uses watchtower is a more "standard" way. Anyway, as I also said earlier, thanks a lot for your awesome work with Watchtower, and sorry for this way too long report... :smile:

If this is indeed the intended behavior, don't hesitate to close this bug report and I'll open a feature request instead !

[github-actions[bot]]

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]

This is indeed intended. The generally used way to get the information you mention above is with notifications, but having it output the summary after a run-once would absolutely make sense.

Perhaps a flag that enables the summary to be printed after each session could be added for batch processing etc?
The way I am thinking it would work is for a the flag to add logger:// to the notifications and make shoutrrr logs write to stdout. That way you could also customize the output to use JSON or whatever is suitable.

The commonly used flag for these kinds of usage is --porcelain, but it's also a bit confusing as it's basically doing the opposite (turning a default porcelain output to a plumping one)

[Antiz96]

I'll surely be interested in such a feature. Enabling that through a flag seems to be a good approach indeed !

Do you want me to close this issue and open a feature request instead ?

[piksel]

Let's continue using this issue for now. I made a PoC of this, and the current output looks like this:

❯ go run . --run-once --porcelain
INFO[0001] Watchtower v0.0.0-unknown
INFO[0001] Using notifications: logger
INFO[0001] Checking all containers (except explicitly disabled with label)
INFO[0001] Running a one time update.
INFO[0001] Found new localhost:5000/images/demo2 image (2ee44750904d)
INFO[0001] Found new localhost:5000/images/demo1 image (2ea76aa33e1e)
INFO[0002] Stopping /demo1 (6fab0a9f0d1c) with SIGTERM
INFO[0002] Stopping /demo2 (a8fcead61dca) with SIGTERM
INFO[0003] Creating /demo2
INFO[0003] Creating /demo1
INFO[0004] Session done                                  Failed=0 Scanned=3 Updated=2 notify=no
INFO[0004] Waiting for the notification goroutine to finish  notify=no
3 containers matched filter

/demo1 (localhost:5000/images/demo1): Updated
/demo2 (localhost:5000/images/demo2): Updated
/du-registry (registry:2): Fresh

Where the non-INFO lines are stdout.

[Antiz96]

Well, that's perfect already :smiley:

As far as I'm concerned, I would be happy with what you came up with that PoC. I'm primarily looking to get the names of container that got updated through the stdout, so that's good.