As a workaround for the titular issue, I have tried enabling the "imap-hibernate" service on a couple of servers to reduce the number of running imap processes.
Since ~50-60% of clients are in IDLE at any one time, this allows us to reduce the number of running imap processes to less than half of what it was.
After this I have yet to see the "net_connect_unix(imap) failed" errors on these servers, however instead we are now instead seeing a few of these:
imap([redacted])<30266><[redacted]>: Error: imap-master: Failed to import client state: Mailbox INBOX: Couldn't get recently expunged UIDs (uidnext=13479 highest_modseq=1716)
and
imap([redacted])<20055><[redacted]>: Error: imap-master: Failed to import client state: Mailbox INBOX: Couldn't send flag changes imap([redacted])<20055><[redacted]>: NOTIFY failed in the middle of FETCH reply in=0 out=0 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
The former I suspect may be related to our NFS-backed store and simultaneous access from different, since many of the errors are accompanied by other corruption related errors:
imap([redacted])<30266><[redacted]>: Error: Mailbox INBOX: vsize-hdr has invalid size: 36
This whole upgrade is part of a migration to a director-backed system, because we are seeing a too large amount of corruption errors (locking/indexes, etc) assumed to be caused by NFS.
Once we introduce the director cluster in front, these errors should hopefully be strongly reduced. :-)
-- Eirik
On 08/01/2020 15:14, Eirik Rye wrote:
With proctitles below.
Strangely, Dovecot is reporting 12679 imap-login sockets in "pre-login" state, which is about 50% more than there are active TCP connections to the server (8271, of which 7546 are in "imap-login" process according to
ss -tp).On another server, not currently experiencing this issue, the number of TCP sockets appears to more closely match the number of imap-login sockets used (either in pre-login or TLS proxing).
imap:~# ps -f --ppid
pidof dovecot| egrep -v "dovecot/(imap|pop3) " UID PID PPID C STIME TTY TIME CMD dovenull 5262 5260 0 11:48 ? 00:00:00 dovecot/pop3-login dovenull 5263 5260 2 11:48 ? 00:03:53 dovecot/imap-login [724 pre-login + 113 TLS proxies] dovecot 5264 5260 0 11:48 ? 00:01:15 dovecot/anvil [21 connections] root 5265 5260 1 11:48 ? 00:02:18 dovecot/log dovenull 5266 5260 0 11:48 ? 00:00:00 dovecot/pop3-login dovenull 5267 5260 0 11:48 ? 00:00:00 dovecot/pop3-login dovenull 5268 5260 0 11:48 ? 00:00:00 dovecot/pop3-login dovenull 5269 5260 20 11:48 ? 00:35:34 dovecot/imap-login [1073 pre-login + 1199 TLS proxies] dovenull 5270 5260 1 11:48 ? 00:02:25 dovecot/imap-login [615 pre-login + 67 TLS proxies] dovenull 5271 5260 0 11:48 ? 00:01:39 dovecot/imap-login [489 pre-login + 44 TLS proxies] dovenull 5272 5260 14 11:48 ? 00:24:44 dovecot/imap-login [938 pre-login + 720 TLS proxies] dovenull 5273 5260 6 11:48 ? 00:10:30 dovecot/imap-login [845 pre-login + 242 TLS proxies] dovenull 5274 5260 4 11:48 ? 00:06:54 dovecot/imap-login [817 pre-login + 209 TLS proxies] dovenull 5275 5260 0 11:48 ? 00:01:23 dovecot/imap-login [445 pre-login + 36 TLS proxies] dovenull 5276 5260 25 11:48 ? 00:43:14 dovecot/imap-login [1064 pre-login + 1434 TLS proxies] dovenull 5277 5260 1 11:48 ? 00:02:19 dovecot/imap-login [523 pre-login + 58 TLS proxies] dovenull 5278 5260 9 11:48 ? 00:16:19 dovecot/imap-login [937 pre-login + 462 TLS proxies] dovenull 5279 5260 19 11:48 ? 00:33:24 dovecot/imap-login [937 pre-login + 823 TLS proxies] dovenull 5280 5260 1 11:48 ? 00:03:04 dovecot/imap-login [655 pre-login + 92 TLS proxies] dovenull 5281 5260 26 11:48 ? 00:45:20 dovecot/imap-login [969 pre-login + 1450 TLS proxies] dovenull 5282 5260 6 11:48 ? 00:10:55 dovecot/imap-login [917 pre-login + 303 TLS proxies] dovenull 5283 5260 4 11:48 ? 00:08:36 dovecot/imap-login [731 pre-login + 128 TLS proxies] root 5284 5260 2 11:48 ? 00:03:55 dovecot/config dovecot 5285 5260 1 11:48 ? 00:02:19 dovecot/stats [7968 connections] dovecot 5286 5260 3 11:48 ? 00:05:53 dovecot/auth [138 wait, 0 passdb, 0 userdb] 528246 10322 5260 0 14:36 ? 00:00:00 [imap] root 16688 5260 0 14:40 ? 00:00:00 dovecot/imap imap02:~# doveadm process status | grep "^imap-login " | awk "{sum += 2500-\$3} END {print sum}" 20081 imap:~# ps -f --ppidpidof dovecot| grep "dovecot/imap " | wc -l 7937 imap:~# doveadm process status | grep "^imap " | wc -l 7937 imap:~# ss -ntp "( sport = :143 or sport = :993 )" | grep "\"imap\"" | wc -l 559 imap:~# ss -ntp "( sport = :143 or sport = :993 )" | grep "\"imap-login\"" | wc -l 7546 imap:~# ss -ntp "( sport = :143 or sport = :993 )" | wc -l 8271On 08/01/2020 11:33, Eirik Rye wrote:
On 08/01/2020 11:09, Aki Tuomi wrote:
Can you enable 'verbose_proctitle=yes' and maybe compare with ss -tp output?
Thanks for the response!
What exactly did you want to compare?
ss -tpdoes not appear to show cmdline/process title. I enabled it for one server, but will have to wait for users to reconnect and for the issue to reappear there.In the meantime, on another server experiencing the same issue at this moment (same configuration), but no proctitles:
root@imap03:~# doveadm process status | grep "^imap " | wc -l 7564 root@imap03:~# ps aux | grep "dovecot/imap$" | wc -l 7570 root@imap03:~# ss -tp | grep '"imap-login"' | wc -l 8009 root@imap03:~# ss -tp | grep '"imap"' | wc -l 536 root@imap03:~# ss -nt "( sport = :143 or sport = :993 )" | wc -l 8739 root@imap03:~# doveadm who -1 | wc -l 7581
The
ss -tpoutput appears normal (e.g. 8009+536 ~= 8739).