search

jeboehm / docker-mailserver

Docker Mailserver based on the famous ISPMail guide
MIT License
356 stars 93 forks source link

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

Closed kklepper closed 3 years ago

kklepper commented 3 years ago

☺️ 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):

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

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 commented 3 years ago

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

kklepper commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

As i understand - MDA does:

MTA:

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 commented 3 years ago

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 commented 3 years ago

@kklepper Glad if i could help :)