Dovecot continues to enter a failed state with exit code status=75

Submitted by adamjedgar on Thu, 05/07/2020 - 23:02 Pro Licensee

guys this is causing me great problems...

i cannot get the SSL issue resolved after the webmin update 6.09. It has completely stuffed my email functionality on the system.

root@server1 ~]# systemctl status dovecot.service

May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(memberships@flystanwell.com): Server shutting down. in=155 out=2516
May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(ajecreative@skysurf.com.au): Server shutting down. in=155 out=2513
May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(adamjedgar@ajecreative.com.au): Server shutting down. in=201 out=755
May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(president@flystanwell.com): Server shutting down. in=4843 out=7493
May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(treasurer@flystanwell.com): Server shutting down. in=144300 out=33013
May 08 13:42:31 server1.ajecreative.com.au dovecot[776]: imap(treasurer@flystanwell.com): Server shutting down. in=3748 out=60968
May 08 13:42:31 server1.ajecreative.com.au doveadm[6252]: Fatal: Dovecot is not running (read from /var/run/dovecot/master.pid)
May 08 13:42:31 server1.ajecreative.com.au systemd[1]: dovecot.service: Control process exited, code=exited status=75
May 08 13:42:31 server1.ajecreative.com.au systemd[1]: dovecot.service: Unit entered failed state.
May 08 13:42:31 server1.ajecreative.com.au systemd[1]: dovecot.service: Failed with result 'exit-code'.

What can i do to restart dovecot? It refuses to restart without a complete server hard reset...and then only functions for about 15 minutes (i guess this may be dependent on email usage) before it stops working again.

also, even when the dovecot server is working, it is still throwing ssl certificate validation errors to emai client apps.

Ideally, i just need to wipe Dovecot and start over with it. Trouble is, i cannot find a single virtualmin help file that explains how to do this for the current release. What should i do?

Status: 
Active

Comments

Submitted by adamjedgar on Fri, 05/08/2020 - 00:22 Pro Licensee

also...

[root@server1 ~]# ps aux | grep dovecot
dovenull  2313  0.0  0.1  21760  5832 ?        S    14:13   0:00 dovecot/imap-login
secreta+  2315  0.0  0.0  23876  3868 ?        S    14:13   0:00 dovecot/imap
dovenull  4936  0.0  0.1  21760  5636 ?        S    14:51   0:00 dovecot/imap-login
dovenull  4938  0.0  0.1  21760  5712 ?        S    14:51   0:00 dovecot/imap-login
members+  4952  0.0  0.1  23880  4476 ?        S    14:51   0:00 dovecot/imap
adamjed+  4953  0.0  0.1  23868  4572 ?        S    14:51   0:00 dovecot/imap
dovenull  5877  0.0  0.1  21748  5968 ?        S    14:53   0:00 dovecot/imap-login
contact+  6029  0.0  0.0  23536  3920 ?        S    14:53   0:00 dovecot/imap
root      6253  0.0  0.0  18132  2548 ?        Ss   13:42   0:00 /usr/sbin/dovecot
dovecot   6254  0.0  0.0   9492   944 ?        S    13:42   0:00 dovecot/anvil
root      6255  0.0  0.0   9624  2324 ?        S    13:42   0:00 dovecot/log
root      6257  0.0  0.3  29768 12660 ?        S    13:42   0:00 dovecot/config
liaison+  8815  0.0  0.1  23916  4380 ?        S    13:44   0:00 dovecot/imap
preside+ 10156  0.0  0.0  23896  3884 ?        S    14:21   0:00 dovecot/imap
dovenull 13538  0.0  0.1  21748  5636 ?        S    14:55   0:00 dovecot/imap-login
ajecrea+ 13549  0.0  0.1  23892  4468 ?        S    14:55   0:00 dovecot/imap
preside+ 14016  0.0  0.1  24488  4960 ?        S    14:25   0:00 dovecot/imap
dovecot  15172  0.0  0.0  20520  2788 ?        S    14:57   0:00 dovecot/auth
root     19500  0.0  0.0   4276   716 ?        S    15:00   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     19501  0.0  0.0   4276    88 ?        S    15:00   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     19503  0.0  0.0  11104   928 ?        S    15:00   0:00 grep dovecot
dovenull 20675  0.0  0.1  21748  5624 ?        S    14:32   0:00 dovecot/imap-login
contact+ 20686  0.0  0.1  23948  4516 ?        S    14:32   0:00 dovecot/imap
dovenull 23780  0.0  0.1  21748  5636 ?        S    14:34   0:00 dovecot/imap-login
contact+ 23782  0.0  0.1  24592  5160 ?        S    14:34   0:00 dovecot/imap

Submitted by adamjedgar on Fri, 05/08/2020 - 00:44 Pro Licensee

If i stop all dovecot processes in Webmin>system>bootup and Shutdown

then in command shell do the following:

systemctl restart dovecot
systemctl status dovecot

I get the following when i run ps aux | grep dovecot

[root@server1 ~]# ps aux | grep dovecot
root     31916  0.0  0.0  18000  2520 ?        Ss   15:39   0:00 /usr/sbin/dovecot
dovecot  31917  0.0  0.0   9492   988 ?        S    15:39   0:00 dovecot/anvil
root     31918  0.0  0.0   9624  2284 ?        S    15:39   0:00 dovecot/log
root     31921  0.0  0.1  25176  7136 ?        S    15:39   0:00 dovecot/config
dovecot  32001  0.0  0.0  20520  2524 ?        S    15:39   0:00 dovecot/auth
root     32002  0.0  0.0  33204  3768 ?        S    15:39   0:00 dovecot/auth -w
root     32166  0.0  0.0   4276   748 ?        S    15:40   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     32167  0.0  0.0   4276    88 ?        S    15:40   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     32169  0.0  0.0  11104   920 ?        S    15:40   0:00 grep dovecot

Why is there such a big difference in the above compared with the one i posted before i shutdown dovecot completely and restarted it? What do all the "dovenull" entries mean?

Submitted by adamjedgar on Fri, 05/08/2020 - 00:48 Pro Licensee

Also,

[root@server1 ~]# ss -ntpl | grep -e :143 -e :993
LISTEN     0      100          *:993                      *:*                   users:(("dovecot",pid=31916,fd=40))
LISTEN     0      100          *:143                      *:*                   users:(("dovecot",pid=31916,fd=38))
LISTEN     0      100         :::993                     :::*                   users:(("dovecot",pid=31916,fd=41))
LISTEN     0      100         :::143                     :::*                   users:(("dovecot",pid=31916,fd=39))
[root@server1 ~]# ss -ntpl | grep -e :143 -e :587
LISTEN     0      3            *:587                      *:*                   users:(("master",pid=1194,fd=111))
LISTEN     0      100          *:143                      *:*                   users:(("dovecot",pid=31916,fd=38))
LISTEN     0      3           :::587                     :::*                   users:(("master",pid=1194,fd=112))
LISTEN     0      100         :::143                     :::*                   users:(("dovecot",pid=31916,fd=39))

Submitted by adamjedgar on Fri, 05/08/2020 - 05:50 Pro Licensee

I disabled all mail for each virtual server, then stopped all dovecot processes and restarted dovecot again. It restarted.

One by one i have enabled mail for each virtual server which was using it previously except for one.

I have managed i think to narrow this down to affecting just one domain on my server. Unfortunately, this is the domain that also has the most email accounts and usage.I note the following which i need to fix (remove "webmin" and "usermin" below from using this certificate)

This SSL certificate is already being used by : Webmin (flystanwell.com), Webmin, Usermin (host flystanwell.com), Usermin, Dovecot (host flystanwell.com)

Also, i have an update available for webmin-virtual-server 6.09-2. This was the update that i think intiated all of this trouble in the first place prior to be restoring from a backup. Do i try to apply this update again or wait?

I urgently need to get the emails working on this virtual server.

Submitted by adamjedgar on Fri, 05/08/2020 - 07:15 Pro Licensee

Also, i have slowly re enabled the domains where email is needed. The dovecot server has kept working this time and imap appears to be working for now. One thing that does still concern me is the following...

liaison+   350  0.0  0.1  24700  5516 ?        S    15:41   0:00 dovecot/imap
root      1040  0.0  0.1  25380  7512 ?        S    15:43   0:01 dovecot/config
preside+  1730  0.0  0.1  24224  4960 ?        S    19:39   0:00 dovecot/imap
liaison+  2534  0.0  0.0  23876  3920 ?        S    22:00   0:00 dovecot/imap
dovenull  4841  0.0  0.1  21748  5772 ?        S    22:04   0:00 dovecot/imap-login
operati+  4896  0.0  0.1  23876  4680 ?        S    22:04   0:00 dovecot/imap
dovenull  4903  0.0  0.1  21748  5932 ?        S    22:04   0:00 dovecot/imap-login
operati+  4906  0.0  0.0  23536  3956 ?        S    22:04   0:00 dovecot/imap
dovenull  6832  0.0  0.1  21748  5608 ?        S    22:04   0:00 dovecot/imap-login
dovenull  6833  0.0  0.1  21748  5916 ?        S    22:04   0:00 dovecot/imap-login
adamjed+  6835  0.0  0.1  23868  4668 ?        S    22:04   0:00 dovecot/imap
members+  6836  0.0  0.1  23880  4636 ?        S    22:04   0:00 dovecot/imap
dovecot   8721  0.0  0.0  20520  2756 ?        S    22:08   0:00 dovecot/auth
root      8724  0.0  0.0  33304  3720 ?        S    22:08   0:00 dovecot/auth -w
dovenull  8850  0.0  0.1  21748  5836 ?        S    22:08   0:00 dovecot/imap-login
dovenull  8851  0.0  0.1  21748  5768 ?        S    22:08   0:00 dovecot/imap-login
root      8852  0.0  0.0  33304  3752 ?        S    22:08   0:00 dovecot/auth -w
1054      8853  0.0  0.1  23912  4492 ?        S    22:08   0:00 dovecot/imap
ajecrea+  8854  0.0  0.1  23896  4460 ?        S    22:08   0:00 dovecot/imap
root     12599  0.0  0.0   9488   936 ?        S    22:10   0:00 dovecot/ssl-params
root     12989  0.0  0.0   4276   744 ?        S    22:10   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     12990  0.0  0.0   4276    88 ?        S    22:10   0:00 sh -c (ps aux | grep dovecot) 2>&1
root     12992  0.0  0.0  11104   908 ?        S    22:10   0:00 grep dovecot
dovenull 13746  0.0  0.1  21760  5712 ?        S    21:39   0:00 dovecot/imap-login
1054     13853  0.0  0.1  24920  5392 ?        S    21:40   0:00 dovecot/imap
dovenull 13873  0.0  0.1  21760  5836 ?        S    21:40   0:00 dovecot/imap-login
1054     13874  0.0  0.1  24508  5304 ?        S    21:40   0:00 dovecot/imap
dovenull 19184  0.0  0.1  21748  5932 ?        S    21:45   0:00 dovecot/imap-login
contact+ 19198  0.0  0.1  23876  4488 ?        S    21:45   0:00 dovecot/imap
dovenull 20675  0.0  0.1  21760  5664 ?        S    18:58   0:00 dovecot/imap-login
1054     20686  0.0  0.1  24936  4916 ?        S    18:58   0:00 dovecot/imap
dovenull 20821  0.0  0.1  21748  5916 ?        S    21:16   0:00 dovecot/imap-login
adamjed+ 20824  0.0  0.1  23960  4448 ?        S    21:16   0:00 dovecot/imap
dovenull 24830  0.0  0.1  21748  5916 ?        S    21:51   0:00 dovecot/imap-login
1054     24833  0.0  0.1  24864  5132 ?        S    21:51   0:00 dovecot/imap
dovenull 26114  0.0  0.1  21748  5712 ?        S    21:53   0:00 dovecot/imap-login
contact+ 26149  0.0  0.1  23648  4128 ?        S    21:54   0:00 dovecot/imap
dovenull 28955  0.0  0.1  21760  5916 ?        S    16:18   0:00 dovecot/imap-login
liaison+ 28958  0.0  0.1  23904  4628 ?        S    16:18   0:00 dovecot/imap
preside+ 29238  0.0  0.1  24824  4956 ?        S    21:54   0:00 dovecot/imap
dovenull 29845  0.0  0.1  21748  5664 ?        S    21:55   0:00 dovecot/imap-login
1054     29851  0.0  0.1  23872  4604 ?        S    21:55   0:00 dovecot/imap
dovenull 29863  0.0  0.1  21748  5640 ?        S    21:55   0:00 dovecot/imap-login
1054     29864  0.0  0.1  24180  4740 ?        S    21:55   0:00 dovecot/imap
dovenull 30517  0.0  0.1  21748  5964 ?        S    21:56   0:00 dovecot/imap-login
adamjed+ 30521  0.0  0.1  23868  4540 ?        S    21:56   0:00 dovecot/imap
dovenull 30543  0.0  0.1  21760  5916 ?        S    21:56   0:00 dovecot/imap-login
1054     30544  0.0  0.1  23868  4692 ?        S    21:56   0:00 dovecot/imap
dovenull 30551  0.0  0.1  21760  5976 ?        S    21:56   0:00 dovecot/imap-login
1054     30553  0.0  0.1  24344  4912 ?        S    21:56   0:00 dovecot/imap
root     31916  0.0  0.0  18132  2528 ?        Ss   15:39   0:00 /usr/sbin/dovecot
dovecot  31917  0.0  0.0   9492   988 ?        S    15:39   0:00 dovecot/anvil
root     31918  0.0  0.0   9624  2284 ?        S    15:39   0:00 dovecot/log
dovenull 32380  0.0  0.1  21748  5604 ?        S    21:28   0:00 dovecot/imap-login
contact+ 32401  0.0  0.1  23844  4228 ?        S    21:28   0:00 dovecot/imap

should there be so many dovenull entries? Are these supposed to eventually go away or do they stay permanently? Its been about 15 minutes since i sent a group wide email to the various users associated with the dovenull entires. I am conerned that if this is not supposed to still have these entries, then something is preventing them from being terminated. Anyway, i dont know where else to go with this now...I await your feedback Joe.

calderwood's picture
Submitted by calderwood on Mon, 08/31/2020 - 10:14

I have been having issues with Dovecot for at least a year. Every time there's an update to an SSL or a mail server the problems come back. I can always delete all active sessions and restart, usually lasts a few days. Also in the 10-SSL.conf it randomly loses a curly { before a local... line and throws a hissy fit which has to be manually updated.

Currently Vitamin says Dovecot is not working, but it is:

systemctl status dovecot.service
● dovecot.service - Dovecot IMAP/POP3 email server
   Loaded: loaded (/usr/lib/systemd/system/dovecot.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Mon 2020-08-31 10:50:05 EDT; 6min ago
     Docs: man:dovecot(1)
           http://wiki2.dovecot.org/
  Process: 22843 ExecStart=/usr/sbin/dovecot (code=exited, status=89)
  Process: 22839 ExecStartPre=/usr/sbin/portrelease dovecot (code=exited, status=0/SUCCESS)
  Process: 22836 ExecStartPre=/usr/libexec/dovecot/prestartscript (code=exited, status=0/SUCCESS)

Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net systemd[1]: Starting Dovecot IMAP/POP3 email server...
Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net dovecot[22843]: Fatal: Dovecot is already running with PID 4066 (read from /var/run/dovecot/master.pid)
Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net systemd[1]: dovecot.service: control process exited, code=exited status=89
Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net systemd[1]: Failed to start Dovecot IMAP/POP3 email server.
Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net systemd[1]: Unit dovecot.service entered failed state.
Aug 31 10:50:05 s64-202-xxx-xxx.secureserver.net systemd[1]: dovecot.service failed.
[root@s64-202-xxx-xxx ~]# ps aux | grep -v grep | grep dovecot
dovenull  1067  0.0  0.0  46400  4312 ?        S    10:16   0:00 dovecot/imap-login
lisa@eu+  1075  0.0  0.3  71308 19584 ?        S    10:16   0:01 dovecot/imap
root      4066  0.0  0.0  16216   704 ?        Ss   Aug27   0:12 /usr/sbin/dovecot
dovecot   4067  0.0  0.0   9748   448 ?        S    Aug27   0:02 dovecot/anvil
dovenull  8127  0.0  0.0  46400  4308 ?        S    10:29   0:00 dovecot/imap-login
postmas+  8136  0.0  0.0  18032  2572 ?        S    10:29   0:00 dovecot/imap
dovenull  8230  0.0  0.0  46400  4304 ?        S    10:29   0:00 dovecot/imap-login
david@e+  8237  0.0  0.3  66444 18424 ?        S    10:29   0:01 dovecot/imap
dovenull  8452  0.0  0.0  46400  4308 ?        S    10:29   0:00 dovecot/imap-login
david@e+  8457  0.0  0.0  17672  2320 ?        S    10:29   0:00 dovecot/imap
dovenull  8692  0.0  0.0  46400  4308 ?        S    10:30   0:00 dovecot/imap-login
postmas+  8696  0.0  0.0  17672  2312 ?        S    10:30   0:00 dovecot/imap
dovenull 15074  0.0  0.0  46400  4308 ?        S    10:39   0:00 dovecot/imap-login
pam@hr-+ 15080  0.0  0.0  18828  3676 ?        S    10:39   0:00 dovecot/imap
dovenull 15097  0.0  0.0  46400  4308 ?        S    10:39   0:00 dovecot/imap-login
pam@hr-+ 15103  0.0  0.0  18440  3632 ?        S    10:39   0:00 dovecot/imap
dovenull 16022  0.0  0.0  46400  4304 ?        S    10:40   0:00 dovecot/imap-login
pam@hr-+ 16029  0.0  0.0  17984  2864 ?        S    10:40   0:00 dovecot/imap
dovenull 21213  0.0  0.0  46400  4304 ?        S    10:47   0:00 dovecot/imap-login
lisa@eu+ 21217  0.0  0.0  17564  2204 ?        S    10:47   0:00 dovecot/imap

Then if I kill all dovecot and restart, it starts working until the next update or change to email:

systemctl status dovecot.service
● dovecot.service - Dovecot IMAP/POP3 email server
   Loaded: loaded (/usr/lib/systemd/system/dovecot.service; enabled; vendor preset: disabled)
   Active: active (running) since Mon 2020-08-31 11:12:03 EDT; 6s ago
     Docs: man:dovecot(1)
           http://wiki2.dovecot.org/
  Process: 7387 ExecStart=/usr/sbin/dovecot (code=exited, status=0/SUCCESS)
  Process: 7384 ExecStartPre=/usr/sbin/portrelease dovecot (code=exited, status=0/SUCCESS)
  Process: 7381 ExecStartPre=/usr/libexec/dovecot/prestartscript (code=exited, status=0/SUCCESS)
Main PID: 7389 (dovecot)
   CGroup: /system.slice/dovecot.service
           ├─7389 /usr/sbin/dovecot
           ├─7391 dovecot/anvil
           ├─7392 dovecot/log
           └─7394 dovecot/config

Aug 31 11:12:03 s64-202-xxx.secureserver.net systemd[1]: Starting Dovecot IMAP/POP3 email server...
Aug 31 11:12:03 s64-202-xxx.secureserver.net systemd[1]: Started Dovecot IMAP/POP3 email server.

Ilia's picture
Submitted by Ilia on Mon, 08/31/2020 - 17:30

I can always delete all active sessions and restart, usually lasts a few days. Also in the 10-SSL.conf it randomly loses a curly { before a local... line and throws a hissy fit which has to be manually updated.

When did this happen last? We are sure that it was fixed in the latest Webmin 1.955 and Virtualmin 6.12!