Watchtower: Failed to send notification email

[ogmueller]

Describe the bug
When adding a postfix container as an SMTP, watchtower is not able to connect to it, even though other containers are. The log entry is:
Failed to send notification email: dial tcp 172.25.0.2:25: connect: connection refused

To Reproduce
Just start up this docker-compose.yml and the error occurs. It also occurs with watchtower v0.3.11 and others.

version: "3.7"

services:
  watchtower:
    container_name: watchtower
    image: containrrr/watchtower:latest
    environment:
      WATCHTOWER_MONITOR_ONLY: "true"
      WATCHTOWER_DEBUG: "true"
      WATCHTOWER_NOTIFICATIONS: email
      WATCHTOWER_NOTIFICATION_EMAIL_FROM: [email protected]
      WATCHTOWER_NOTIFICATION_EMAIL_TO: [email protected]
      WATCHTOWER_NOTIFICATION_EMAIL_SERVER: postfix
      WATCHTOWER_NOTIFICATION_EMAIL_SERVER_PORT: 25
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
    depends_on:
      - postfix

  postfix:
    image: freinet/postfix-relay:latest
    expose:
      - 25
    environment:
      MAILNAME: mail.example.com

Expected behavior
No connection error.

Environment

# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04 LTS
Release:    20.04
Codename:   focal

 # docker --version
Docker version 19.03.8, build afacb8b7f0



md5-11032564c60eb25dab1ba0d3b7b37895



# docker logs -f watchtower
time="2020-04-19T13:13:03+02:00" level=info msg="Running a one time update."
time="2020-04-19T13:13:03+02:00" level=debug msg="Checking containers for updated images"
time="2020-04-19T13:13:03+02:00" level=debug msg="Retrieving running containers"
Failed to send notification email:  dial tcp 172.25.0.2:25: connect: connection refused
time="2020-04-19T13:13:03+02:00" level=debug msg="Pulling containrrr/watchtower:latest for /watchtower"
time="2020-04-19T13:13:03+02:00" level=debug msg="No credentials for containrrr in /config.json"
time="2020-04-19T13:13:03+02:00" level=debug msg="Got image name: containrrr/watchtower:latest"
time="2020-04-19T13:13:03+02:00" level=debug msg="Got auth value: "
time="2020-04-19T13:13:05+02:00" level=debug msg="No new images found for /watchtower"
time="2020-04-19T13:13:05+02:00" level=debug msg="Pulling freinet/postfix-relay:latest for /watchtower_postfix_1"
time="2020-04-19T13:13:05+02:00" level=debug msg="No credentials for freinet in /config.json"
time="2020-04-19T13:13:05+02:00" level=debug msg="Got image name: freinet/postfix-relay:latest"
time="2020-04-19T13:13:05+02:00" level=debug msg="Got auth value: "
time="2020-04-19T13:13:06+02:00" level=debug msg="No new images found for /watchtower_postfix_1"



md5-da94c35b1e853e0816d11abac70eee54



→ telnet postfix 25
Connected to postfix
220 mail.example.com ESMTP



md5-bda83354cbd4eb2ae761515f658a4f6e



helo test.com
mail from: <[email protected]>
rcpt to: <[email protected]>
250 2.1.5 Ok
data
some text
.



md5-1289967da1f292caa9000d43a3a2e9ab



→ telnet postfix 25
Connected to postfix
220 mail.example.com ESMTP
helo test.com
250 mail.example.com
mail from: <[email protected]>
250 2.1.0 Ok
rcpt to: <[email protected]>
250 2.1.5 Ok
data
354 End data with <CR><LF>.<CR><LF>
some text
.
250 2.0.0 Ok: queued as 3E8F92DA7

It works, so I assume the general postfix and network setup should be ok.

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

[kevdogg]

@ogmueller - Have you tried sending mail on the command line from the watchtower container through the postfix email forwarder?

[ogmueller]

As far as I saw, there is no shell nor other tools in the image to actually try that out.

[simskij]

As far as I saw, there is no shell nor other tools in the image to actually try that out.

Correct. That would require you to customize the dockerfile to use alpine and build it yourself.

[ogmueller]

Ok, I've found the problem. Our certificates didn't match the docker container name and a connection was refused by the message:
Failed to send notification email: x509: certificate is valid for *.domain.com, not postfix

It worked once I've added a network alias to the postfix container

    networks:
      watchtower:
        aliases:
          - smtp.domain.com

and used that alias in the watchtower container

      WATCHTOWER_NOTIFICATION_EMAIL_SERVER: smtp.domain.com

Even though I had turned on WATCHTOWER_DEBUG, this message was not shown. I had to build my own container using dockerfiles/Dockerfile.dev-self-contained. That one finally gave me the right hint.

I don't know the differences between the "normal" and "dev-self-contained" build version, but it would be very helpful to output those kind of errors with a normal (latest) version as well.

[simskij]

That's awesome! Would you mind writing a couple of sentences on it in the docs?

[ogmueller]

Done as pull request. Hope it fits the documentation style.

It would be still helpful to output the error described above.

[ogmueller]

I wanted to try to use WATCHTOWER_NOTIFICATION_EMAIL_SERVER_TLS_SKIP_VERIFY to solve this issue's problem and actually bumped into another problem with the described docker-compose.yml.

When starting up watchtower, it will immediately tries to connect to the SMTP server, which results in
Failed to send notification email: dial tcp 192.168.96.2:25: connect: connection refused.

Using WATCHTOWER_NOTIFICATION_EMAIL_DELAY doesn't seem to help. I set it to a couple of seconds, but watchtower still tries to connect without any delay.

[simskij]

That's interesting! Thank you for reporting that issue!

[simskij]

@piksel Do you have any idea on this?

[piksel]

Well, the error message makes more sense now at least. The email delay has been implemented since v0.3.9, and should be working. The only way to bypass the delay when sending email notifications, as far as I can tell, is by using the Fire method, but that does seem unused.

@ogmueller Do you mean that the delay is totally omitted, or that it doesn't work regardless of the delay? It doesn't look like the delay is happening in a separate goroutine, so the stall might also affect the watched containers (including the Postfix one).

[ogmueller]

Yes, it is omitted at least from the connection point of view. Don't know, if the first email is hold back, but the connect is done immediately.

So if I put in the following ENV to the docker-compose.yml:
WATCHTOWER_NOTIFICATION_EMAIL_DELAY: 60
I would assume, that there is no SMTP connect for 60 seconds.

This is not the case. This is the composer logs from the beginning:

time="2020-05-09T13:29:43+02:00" level=info msg="Running a one time update."
time="2020-05-09T13:29:43+02:00" level=debug msg="Checking containers for updated images"
time="2020-05-09T13:29:43+02:00" level=debug msg="Retrieving running containers"
Failed to send notification email:  dial tcp 172.18.0.2:25: connect: connection refused
time="2020-05-09T13:29:43+02:00" level=debug msg="Pulling containrrr/watchtower:latest for /watchtower"
time="2020-05-09T13:29:43+02:00" level=debug msg="No credentials for containrrr in /config.json"
time="2020-05-09T13:29:43+02:00" level=debug msg="Got image name: containrrr/watchtower:latest"
time="2020-05-09T13:29:43+02:00" level=debug msg="Got auth value: "

As you can see watchtower is trying to connect to the SMTP in the same second it starts. It gives the SMTP container zero time to start up and get ready. This is probably the biggest problem in such a setup.

[piksel]

I found where Fire was being used. It's how the notififications hooks into the log system (logrus).

That means that any log messages above the log level set by notifications-level will be sent using the email notifier (if configured) without any delay.

[devbots-lock-issue[bot]]

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