Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

What does status unhealthy mean, esp. for mailserver-mda, and how to avoid it? #132

Closed
kklepper opened this issue Jun 24, 2021 · 11 comments
Closed

Comments

@kklepper
Copy link

☺️ Please check the troubleshooting page before opening a new issue. ☺️

https://github.com/jeboehm/docker-mailserver/wiki/Troubleshooting

Describe the bug
A clear and concise description of what the bug is.

I stumbled upon this problem by chance when I realized I could not start the webmail client.

It turned out docker-mailserver_web was unhealthy. Remedy was to stop and restart the service.

In order to monitor this, I installed a cron job to be run every 5 minutes to check all mailserver jobs for healthy-ness; restart them if unhealthy and notify via email.

After a few days it turns out that it is only docker-mailserver_mda which falls into unhealthy-state, but this happens pretty often, several dozen times a day, mostly at least once every hour. As the job runs once per 5 minutes, it also happens that the script is triggered 2 or 3 times in a row, so stopping and starting may not help always.

To Reproduce
Steps to reproduce the behavior:

I do not know what unhealthy means especially for docker-mailserver_mda and how it is triggered.

Also I do not know if an unhealthy docker-mailserver_mda has any bad consequences like an unhealthy docker-mailserver_web has.

Expected behavior
A clear and concise description of what you expected to happen.

Once healthy, a container should stay healthy.

Screenshots
If applicable, add screenshots to help explain your problem.

Docker environment (please complete the following information):

  • Output of docker info

mail 20:03:51 :~# docker info
Client:
Context: default
Debug Mode: false
Plugins:
app: Docker App (Docker Inc., v0.9.1-beta3)
buildx: Build with BuildKit (Docker Inc., v0.5.1-docker)
scan: Docker Scan (Docker Inc.)

Server:
Containers: 24
Running: 24
Paused: 0
Stopped: 0
Images: 109
Server Version: 20.10.6
Storage Driver: overlay2
Backing Filesystem: xfs
Supports d_type: true
Native Overlay Diff: true
userxattr: false
Logging Driver: json-file
Cgroup Driver: cgroupfs
Cgroup Version: 1
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: active
NodeID: ipd46l0g26uldgf5lzoca2dkz
Is Manager: true
ClusterID: m7r3cr8atcih1i8gqcind6f4m
Managers: 1
Nodes: 1
Default Address Pool: 10.0.0.0/8
SubnetSize: 24
Data Path Port: 4789
Orchestration:
Task History Retention Limit: 5
Raft:
Snapshot Interval: 10000
Number of Old Snapshots to Retain: 0
Heartbeat Tick: 1
Election Tick: 10
Dispatcher:
Heartbeat Period: 5 seconds
CA Configuration:
Expiry Duration: 3 months
Force Rotate: 0
Autolock Managers: false
Root Rotation In Progress: false
Node Address: 217.160.241.84
Manager Addresses:
217.160.241.84:2377
Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 05f951a3781f4f2c1911b05e61c160e9c30eaa8e
runc version: 12644e614e25b05da6fd08a38ffa0cfe1903fdec
init version: de40ad0
Security Options:
seccomp
Profile: default
Kernel Version: 4.18.0-240.22.1.el8_3.x86_64
Operating System: CentOS Linux 8
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 7.562GiB
Name: mail
ID: WOR3:ER2I:UNFU:R3IN:TVMJ:A5RJ:DEFC:J7UQ:KFJK:CFYX:KGEK:K4QF
Docker Root Dir: /var/lib/docker
Debug Mode: false
Username: kklepper
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false

  • Output of docker-compose version

mail 20:16:08 :~# docker-compose version
docker-compose version 1.29.2, build 5becea4c
docker-py version: 5.0.0
CPython version: 3.7.10
OpenSSL version: OpenSSL 1.1.0l 10 Sep 2019

Additional context
Add any other context about the problem here.

@vassad
Copy link

vassad commented Jun 26, 2021

Hey!
Try to look up for logs (command below shows last 50 lines):
sudo docker container logs dockermailserver_mta_1 --tail 50

@kklepper
Copy link
Author

@vassad

Thank you for the hint! It is always the same:

Jun 26 09:22:07 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<y21EyqfFeYp/AAAB>
Jun 26 09:22:37 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<ZjYXzKfFZ4R/AAAB>

What can I do about it?

I notice that the load of the machine is decently high. Can this be the cause? If so, how to alleviate it?

@kklepper
Copy link
Author

@vassad

It sure looks like the problem is related to load.

Load is low right now, I will check what happens if load is high again and I do not stop and start -- behavior should be the same.

I will have to wait for a week or so and then for days load will be high again.

@vassad
Copy link

vassad commented Jun 26, 2021

@kklepper yes, it seems to be the load issue.
BTW what are the logs for _web and _mda when they are unhealthy?
And what is the real consequence - the post can not be delivered TO your domain, or FROM your domain, or/and web interface is stuck?

@kklepper
Copy link
Author

It turns out that load is not the issue. I got one email with load 0.79 so far.

But even if state is healthy, there are errors in the log as I witnessed right now (time is UTC):


Jun 26 17:03:53 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<V6ywPa7FTa5/AAAB>
Jun 26 17:03:55 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<SGPWPa7Fl8ZUjkYC>
Jun 26 17:04:23 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<mqd/P67FM6F/AAAB>
Jun 26 17:04:54 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<B3dOQa7FG5R/AAAB>
Jun 26 17:05:24 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<CHkdQ67Fo6J/AAAB>
Jun 26 17:05:54 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<A4HsRK7FObZ/AAAB>
Jun 26 17:06:25 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<eoK7Rq7FQ7B/AAAB>
Jun 26 17:06:55 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<WKWKSK7FlZR/AAAB>
Jun 26 17:07:25 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<26pZSq7FC6p/AAAB>
Jun 26 17:07:56 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<YLsoTK7FbZt/AAAB>
Jun 26 17:08:26 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<LIL3Ta7F47J/AAAB>
Jun 26 17:08:56 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Rp7GT67Fs4R/AAAB>
Jun 26 17:09:27 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<z4GVUa7F8Zl/AAAB>
Jun 26 17:09:57 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<OWdkU67Fc6p/AAAB>
Jun 26 17:10:27 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4JQzVa7F17J/AAAB>
Jun 26 17:10:58 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<KkYDV67FnZJ/AAAB>
Jun 26 17:11:28 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<8FDSWK7FmYV/AAAB>
Jun 26 17:11:59 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<jDmhWq7FxYV/AAAB>
Jun 26 17:12:29 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<i2BwXK7FNYR/AAAB>
Jun 26 17:12:59 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<FC0/Xq7FH7B/AAAB>
Jun 26 17:13:30 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<VzsOYK7FM7R/AAAB>
Jun 26 17:13:56 imap-login: Info: Disconnected (no auth attempts in 1 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<CeeZYa7F1shUjkYC>
Jun 26 17:14:00 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<byHdYa7Fy5t/AAAB>
Jun 26 17:14:30 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<DC2sY67FpaJ/AAAB>

To me it looks like the last error results in a healthy state, though. Confusing.

The mail was triggered at 16:50 local time, so the following excerpt applies:

Jun 26 14:50:02 lmtp(6650): Info: Connect from 192.168.208.3
Jun 26 14:50:02 lmtp(service@voxx.biz)<6650><N2QxJpo+12D6GQAAh5ethQ>: Info: sieve: msgid=<202106261450.15QEo1np1413336@mail.voxx.biz>: stored mail into mailbox 'INBOX'
Jun 26 14:50:02 lmtp(6650): Info: Disconnect from 192.168.208.3: Client has quit the connection (state=READY)
Jun 26 14:50:20 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<BhMPYKzF/6l/AAAB>
Jun 26 14:50:50 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<HgzeYazFQ6F/AAAB>

What to learn from this?

@kklepper
Copy link
Author

status is healthy but the log does not look nice, in particular the last line:

error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<nEFpHLHFsJ5UjkYC>

Jun 26 20:18:42 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<N7lj9rDFP5R/AAAB>
Jun 26 20:18:53 imap-login: Info: Disconnected (no auth attempts in 2 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<CWIL97DFEJNUjkYC>
Jun 26 20:18:53 imap-login: Info: Login: user=<wp@voxx.biz>, method=PLAIN, rip=84.142.70.2, lip=192.168.208.6, mpid=13401, TLS, session=<SkAQ97DFK/pUjkYC>
Jun 26 20:18:53 imap-login: Info: Login: user=<wp@wpopken.de>, method=PLAIN, rip=84.142.70.2, lip=192.168.208.6, mpid=13403, TLS, session=<6EEQ97DFQpJUjkYC>
Jun 26 20:18:53 imap-login: Info: Login: user=<service@voxx.biz>, method=PLAIN, rip=84.142.70.2, lip=192.168.208.6, mpid=13404, TLS, session=<3kIQ97DFCu1UjkYC>
Jun 26 20:19:12 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<gScz+LDFI7V/AAAB>
Jun 26 20:19:43 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<ap0E+rDFAaJ/AAAB>
Jun 26 20:20:13 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Z8fT+7DFZbJ/AAAB>
Jun 26 20:20:43 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<1aii/bDFg5V/AAAB>
Jun 26 20:21:14 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<MeBx/7DFXYB/AAAB>
Jun 26 20:21:44 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<X0FBAbHF64B/AAAB>
Jun 26 20:22:14 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<9lsQA7HFuax/AAAB>
Jun 26 20:22:45 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<C6TfBLHF641/AAAB>
Jun 26 20:23:15 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<CMKuBrHF85J/AAAB>
Jun 26 20:23:45 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<XdF9CLHF+Yh/AAAB>
Jun 26 20:24:16 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4RxNCrHFsa1/AAAB>
Jun 26 20:24:46 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<5P8bDLHFlap/AAAB>
Jun 26 20:25:16 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<ZDvrDbHFPZN/AAAB>
Jun 26 20:25:47 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<MBy7D7HFXYd/AAAB>
Jun 26 20:25:53 submission-login: Info: Remote closed connection: user=<>, rip=185.167.96.138, lip=192.168.208.6, session=<7HUcELHFTOm5p2CK>
Jun 26 20:26:17 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<lkaKEbHFV4V/AAAB>
Jun 26 20:26:48 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Zj9ZE7HFBZh/AAAB>
Jun 26 20:27:18 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<d5goFbHFeY5/AAAB>
Jun 26 20:27:48 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<P5f3FrHFX4V/AAAB>
Jun 26 20:28:19 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<nNPGGLHFMZR/AAAB>
Jun 26 20:28:49 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4w2WGrHFGap/AAAB>
Jun 26 20:29:19 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<jIZlHLHFY5R/AAAB>
Jun 26 20:29:20 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<nEFpHLHFsJ5UjkYC>

@kklepper
Copy link
Author

What does Aborted login (no auth attempts in 0 secs): mean, and why do we have that?

I am still at a loss: it is definitely not high load, but the same pattern all over (Disconnected/Aborted login/Info: Remote closed connection/Error: smtp-server/Info: Read failure), with and without unhealthy state:

Jun 27 11:44:22 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<rOLW5L3F87BUjkYC>
Jun 27 11:44:32 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=</Mlz5b3F+5B/AAAB>
Jun 27 11:45:03 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<uEVE573F1ZV/AAAB>
Jun 27 11:45:33 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<llsT6b3FZ7B/AAAB>
Jun 27 11:46:03 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<8bji6r3F16t/AAAB>
Jun 27 11:46:34 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<5cex7L3FHbV/AAAB>
Jun 27 11:47:04 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<gc6A7r3FeZd/AAAB>
Jun 27 11:47:34 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<fOhP8L3FVZh/AAAB>
Jun 27 11:48:05 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<l+ge8r3FI7d/AAAB>
Jun 27 11:48:35 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<i0Xu873F1YN/AAAB>
Jun 27 11:49:05 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<+Jq99b3Fkat/AAAB>
Jun 27 11:49:36 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<fseM973F26x/AAAB>
Jun 27 11:50:06 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Vu9c+b3F96B/AAAB>
Jun 27 11:50:36 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<v9Mr+73F56h/AAAB>
Jun 27 11:51:07 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<TyL7/L3FzZl/AAAB>
Jun 27 11:51:37 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<A/DJ/r3FAbB/AAAB>
Jun 27 11:52:08 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<r9SYAL7Fo6R/AAAB>
Jun 27 11:52:38 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4cBnAr7FB4h/AAAB>
Jun 27 11:53:08 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<s982BL7FL4F/AAAB>
Jun 27 11:53:39 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<b/AFBr7FH4Z/AAAB>
Jun 27 11:54:09 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Dr7UB77FF4p/AAAB>
Jun 27 11:54:22 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<zTyaCL7FafRUjkYC>
Jun 27 11:54:39 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<V7WjCb7FaYd/AAAB>
Jun 27 11:55:10 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<96NyC77Fg7V/AAAB>
Jun 27 11:55:40 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<HPZBDb7FC6t/AAAB>
Jun 27 11:56:10 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<OxkRD77FKaV/AAAB>
Jun 27 11:56:18 submission-login: Info: Remote closed connection: user=<>, rip=101.99.94.119, lip=192.168.208.6, session=<rG+BD77Fto9lY153>
Jun 27 11:56:18 submission-login: Error: smtp-server: conn 101.99.94.119:36800 [1]: Connection lost: read(SSL (conn:101.99.94.119:36800,id=1)) failed: SSL_accept() failed: error:1417A0C1:SSL routines:tls_post_process_client_hello:no shared cipher
Jun 27 11:56:18 submission-login: Info: Read failure: user=<>, rip=101.99.94.119, lip=192.168.208.6, TLS handshaking: SSL_accept() syscall failed: Invalid argument, session=<VI2ED77FwI9lY153>
Jun 27 11:56:41 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<JBfgEL7Fj6t/AAAB>
Jun 27 11:57:11 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<J1mvEr7FuZJ/AAAB>
Jun 27 11:57:41 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<6W5+FL7F27Z/AAAB>
Jun 27 11:58:12 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<XVRNFr7FV7V/AAAB>
Jun 27 11:58:42 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<7jscGL7Fzap/AAAB>
Jun 27 11:59:12 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<2B3rGb7Fu6d/AAAB>
Jun 27 11:59:43 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Mhi6G77FB7Z/AAAB>
Jun 27 12:00:13 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<LFSJHb7FubN/AAAB>
Jun 27 12:00:43 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4GNYH77FP6x/AAAB>
Jun 27 12:01:14 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<zIAnIb7FSbJ/AAAB>
Jun 27 12:01:44 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<VHz2Ir7Fh5V/AAAB>
Jun 27 12:02:14 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<CKnFJL7FU5p/AAAB>
Jun 27 12:02:45 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<R9WUJr7Fw5F/AAAB>
Jun 27 12:03:15 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<X7VjKL7FQ7Z/AAAB>
Jun 27 12:03:45 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<jJIyKr7FFaR/AAAB>
Jun 27 12:04:16 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<TosBLL7FFax/AAAB>
Jun 27 12:04:22 imap-login: Info: Disconnected (no auth attempts in 0 secs): user=<>, rip=84.142.70.2, lip=192.168.208.6, TLS handshaking: SSL_accept() failed: error:14094412:SSL routines:ssl3_read_bytes:sslv3 alert bad certificate: SSL alert number 42, session=<h2xdLL7F2+RUjkYC>
Jun 27 12:04:46 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<9YbQLb7FC4p/AAAB>
Jun 27 12:05:17 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<4qOfL77FF5Z/AAAB>
Jun 27 12:05:47 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<x6luMb7FPYN/AAAB>
Jun 27 12:06:17 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Gbk9M77FV7V/AAAB>
Jun 27 12:06:48 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<M5YONb7FV6B/AAAB>
Jun 27 12:07:18 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<n0XdNr7FqY5/AAAB>
Jun 27 12:07:48 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<wxStOL7FTbN/AAAB>
Jun 27 12:08:19 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<Vhl8Or7F1aN/AAAB>
Jun 27 12:08:49 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<O3NLPL7Fe41/AAAB>
Jun 27 12:09:19 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<n88aPr7FM7V/AAAB>
Jun 27 12:09:50 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<uYLpP77FYaZ/AAAB>
Jun 27 12:10:20 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<cHG4Qb7FF6J/AAAB>
Jun 27 12:10:50 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<3k6HQ77FI5F/AAAB>
Jun 27 12:11:21 imap-login: Info: Aborted login (no auth attempts in 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<k6JWRb7FbYd/AAAB>
Jun 27 12:11:51 imap-login: Info: Disconnected (disconnected before auth was ready, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<wWYlR77FVaZ/AAAB>

@kklepper
Copy link
Author

Do I understand correctly?

MTA delivers mail, MDA distributes this mail to users? As I send an email if I detect unhealthy state and this email is distributed correctly, where is the problem?

As I receive very little mail on this account, can it be that the errors are triggered because there is no mail to be delivered?

@vassad
Copy link

vassad commented Jun 27, 2021

As i understand - MDA does:

  • Authentification for receive/send e-mail over secure ports
  • SSL encryption of e-mails
  • relay prepared e-mail message via MTA relay using internal-network connection

MTA:

  • receive e-mail from external mailboxes like gmail.com etc. using 25 port
  • send e-mail prepared from MDA as via relay

I also have aborted logins in MDA logs, i think it is spammers trying to send emails via our servers.

As for unhealthy state - i got some situations on a weak hosting VPS - especially the antivirus got too high cpu usage showing in htop.
Right now using an ordinal PC behind OpenVPN as a mailserver - never got unhealthy anymore.
Also about healty/unhealty states:
https://blog.couchbase.com/docker-health-check-keeping-containers-healthy/
unhealthy – If a single run of the takes longer than the specified timeout then it is considered unhealthy. If a health check fails then the will run retries number of times and will be declared unhealthy if the still fails.

And again:
And what is the real consequence - the mail can not be delivered TO your domain, or FROM your domain, or/and web interface is stuck?
I think if the mails are transferred successfully to both directions - let it be like this?
Also you could try to look at rspamd web-interface to look for the mail amounts - perhaps spammers have a big attack?

Mail amount should not affect the errors at all...

@kklepper
Copy link
Author

Thank you very much, vassad!

Spam does not seem to be the issue.

image

I also have aborted logins in MDA logs, i think it is spammers trying to send emails via our servers.

This may very well be the case and would explain the errors and why normal business is ok.

I think I have learned something and should just check docker-mailserver_web_1 -- which did not ever have issues since I noticed it once.

@vassad
Copy link

vassad commented Jun 27, 2021

@kklepper Glad if i could help :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants