Thx! It seems these processes are in state "dovecot/imap-login [1 pre-login]". Concerning logs, the only thing that seems suspicious to me is: Jan 31 00:33:05 static dovecot: imap-login: Disconnected (no auth attempts in 5 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS handshaking: Connection closed, session=<QD/tiia6aKlb6BxS> Jan 31 00:33:05 static dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS handshaking: SSL_accept() failed: error:1408F09C:SSL routines:ssl3_get_record:http request, session=<OCruiia6fstb6BxS> Jan 31 00:33:06 static dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS handshaking: SSL_accept() failed: error:1408F09C:SSL routines:ssl3_get_record:http request, session=<SaPviia6HMxb6BxS> The IPs in question are not our own IPs. Since restarting (about 45 minutes), I have about a dozen of the "Disconnected (no auth attempts" and exactly 13 of the pre-login processes. In fact, the number of pre-login processes just jumped by 2 and the log just shows 2 new "Disconnected (no auth attempts in 0 secs)" This might have something to do with it. Version is 2.3.4.1. It's a production system, I'd like to avoid having to compile my own version of dovecot unless there's no way around it. Greetings, Wolfgang On 2/5/21 10:51 AM, Aki Tuomi wrote:> Can you set > > verbose_proctitle = yes > > this should provide more information what the process is up to. > > Can you also check your logs? > > Aki > >> On 05/02/2021 11:46 Wolfgang <adminkram at tripelspark.de> wrote: >> >> >> Hi, >> >> Sorry, the problem is back! Not solved, again no change except that I >> lowered the limits again and restarted dovecot. Here is what it looks like: >> >> lsof -a -i4 -i6 -itcp | fgrep imap-logi | wc >> 9 >> >> --> There are 9 TCP connections to imap-login. >> >> ps aux | fgrep imap-login | wc >> 81 >> ps aux | fgrep imap | wc >> 90 >> >> --> There are 90-81 = 9 IMAP worker processes (OK) and 81 imap-login >> processes (not OK). Thunderbird cannot connect again. >> >> ps auxf | fgrep dove >> root 28118 0.0 0.0 4200 2752 ? Ss Feb03 0:02 >> /usr/sbin/dovecot -F >> dovecot 28138 0.0 0.0 4176 2224 ? S Feb03 0:01 \_ >> dovecot/anvil >> root 28139 0.0 0.0 4172 2436 ? S Feb03 0:00 \_ >> dovecot/log >> root 28140 0.0 0.0 6764 4636 ? S Feb03 0:05 \_ >> dovecot/config >> dovecot 28143 0.0 0.0 5360 3584 ? S Feb03 0:01 \_ >> dovecot/stats >> dovenull 28206 0.0 0.0 8200 4652 ? S Feb03 0:02 \_ >> dovecot/imap-login >> USER2 28207 0.0 0.0 6356 3988 ? S Feb03 0:02 \_ >> dovecot/imap >> dovenull 28234 0.0 0.0 8200 4712 ? S Feb03 0:02 \_ >> dovecot/imap-login >> USER1 28235 0.0 0.0 6356 2924 ? S Feb03 0:02 \_ >> dovecot/imap >> dovenull 28275 0.0 0.0 8200 4716 ? S Feb03 0:02 \_ >> dovecot/imap-login >> USER1 28276 0.0 0.0 9416 7308 ? S Feb03 0:03 \_ >> dovecot/imap >> dovenull 19673 0.0 0.0 8212 6380 ? S Feb04 0:00 \_ >> dovecot/imap-login >> USER3 19674 0.0 0.0 14220 7680 ? S Feb04 0:01 \_ >> dovecot/imap >> dovenull 21688 0.0 0.0 8200 6416 ? S Feb04 0:01 \_ >> dovecot/imap-login >> USER2 21690 0.0 0.0 9604 8504 ? S Feb04 0:01 \_ >> dovecot/imap >> dovenull 22398 0.0 0.0 8200 6440 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 22400 0.0 0.0 8200 6384 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 22593 0.0 0.0 8200 6292 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 22595 0.0 0.0 8200 6312 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 22814 0.0 0.0 8200 6324 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 22816 0.0 0.0 8200 6312 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23026 0.0 0.0 8200 6384 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23028 0.0 0.0 8200 6340 ? S Feb04 0:00 \_ >> dovecot/imap-login >> .......(skipped some lines of imap-login)........ >> dovenull 23179 0.0 0.0 8200 6412 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23181 0.0 0.0 8200 6368 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23421 0.0 0.0 8200 6284 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23423 0.0 0.0 8200 6412 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23611 0.0 0.0 8200 6380 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23613 0.0 0.0 8200 6296 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23797 0.0 0.0 8200 6464 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 23799 0.0 0.0 8200 6296 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 24029 0.0 0.0 8200 6300 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 24031 0.0 0.0 8200 6188 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 24205 0.0 0.0 8200 6340 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 24207 0.0 0.0 8200 6320 ? S Feb04 0:00 \_ >> dovecot/imap-login >> dovenull 5628 0.0 0.0 8212 6408 ? S 08:59 0:00 \_ >> dovecot/imap-login >> USER1 5629 0.0 0.0 7844 6460 ? S 08:59 0:00 \_ >> dovecot/imap >> optores 5630 0.0 0.0 6356 4444 ? S 08:59 0:00 \_ >> dovecot/imap >> USER1 5631 0.0 0.0 6372 4568 ? S 08:59 0:00 \_ >> dovecot/imap >> dovenull 6373 0.0 0.0 8200 6224 ? S 09:43 0:00 \_ >> dovecot/imap-login >> USER1 6375 0.0 0.0 7052 5900 ? S 09:43 0:00 \_ >> dovecot/imap >> >> The config is the same as last time except for this: >> >> auth_worker_max_count = 100 >> default_process_limit = 80 >> >> Which should be more than enough. >> >> Any ideas? >> Wolfgang >> >> On 2/3/21 8:19 PM, Wolfgang wrote: >>> Hi, >>> >>>> But as Aki said, doveconf -n is crucial, especially since you upgraded >>> from an older version. >>>> >>> >>> Thank you for your response. Unfortunately, I missed the first e-mail a >>> few days ago. >>> >>> Interestingly it does no longer happen since a few days. We're seeing >>> one IMAP and one IMAP-LOGIN process per connection now which is the >>> expected behavior. >>> >>> It's completely unclear to me why this does not longer happen now. >>> >>> Anyway, here's the doveconf output in case you spot something. >>> >>> Thank you, >>> Wolfgang >>> >>> # 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf >>> # Pigeonhole version 0.5.4 () >>> # OS: Linux 4.19.0-11-amd64 x86_64 Debian 10.7 >>> # Hostname: static...... >>> auth_mechanisms = scram-sha-1 digest-md5 cram-md5 plain >>> auth_worker_max_count = 300 >>> default_process_limit = 200 >>> first_valid_uid = 1000 >>> hostname = ....... >>> log_timestamp = "%Y-%m-%d %H:%M:%S " >>> mail_location = maildir:~/Maildir >>> mail_plugins = quota acl >>> mail_privileged_group = mail >>> mail_server_admin = postmaster at ....... >>> managesieve_notify_capability = mailto >>> managesieve_sieve_capability = fileinto reject envelope >>> encoded-character vacation subaddress comparator-i;ascii-numeric >>> relational regex imap4flags copy include variables body enotify >>> environment mailbox date index ihave duplicate mime foreverypart >>> extracttext editheader >>> namespace inbox { >>> inbox = yes >>> location >>> mailbox Drafts { >>> special_use = \Drafts >>> } >>> mailbox Junk { >>> special_use = \Junk >>> } >>> mailbox Sent { >>> special_use = \Sent >>> } >>> mailbox "Sent Messages" { >>> special_use = \Sent >>> } >>> mailbox Trash { >>> special_use = \Trash >>> } >>> prefix >>> separator = / >>> type = private >>> } >>> namespace zzzzz { >>> list = children >>> location = maildir:%%h/Maildir-xxx:INDEX=~/index_shared/%%u >>> prefix = shared/%%u/ >>> separator = / >>> subscriptions = no >>> type = shared >>> } >>> passdb { >>> args = /etc/dovecot/shadow >>> driver = passwd-file >>> } >>> plugin { >>> acl = vfile >>> acl_shared_dict = file:/var/mail/shared-%d/shared-mailboxes >>> quota = maildir:User quota >>> quota_rule = *:storage=1G >>> quota_warning = storage=90%% quota-warning 90 %u >>> sieve = file:~/sieve;active=~/dovecot.sieve >>> sieve_extensions = +editheader >>> } >>> postmaster_address = postmaster at xxxxxxx.de >>> protocols = " imap sieve sieve" >>> service auth-worker { >>> chroot = yes >>> user = $default_internal_user >>> } >>> service auth { >>> unix_listener /var/spool/postfix/private/auth { >>> group = postfix >>> mode = 0660 >>> user = postfix >>> } >>> } >>> service imap-login { >>> vsz_limit = 64 M >>> } >>> service managesieve-login { >>> inet_listener sieve { >>> port = 4190 >>> } >>> inet_listener sieve_deprecated { >>> port = 2000 >>> } >>> } >>> ssl_cert = </etc/letsencrypt/live/..../fullchain.pem >>> ssl_client_ca_dir = /etc/ssl/certs >>> ssl_dh = # hidden, use -P to show it >>> ssl_key = # hidden, use -P to show it >>> userdb { >>> args = /etc/dovecot/passwd >>> default_fields = quota_rule=*:storage=1G >>> driver = passwd-file >>> } >>> protocol lda { >>> mail_plugins = quota acl sieve >>> } >>> protocol imap { >>> mail_max_userip_connections = 32 >>> mail_plugins = quota acl imap_quota imap_acl >>> } >>> >
Can you try using https://repo.dovecot.org and see if it happens with 2.3.13 version? Aki> On 05/02/2021 13:42 Wolfgang <adminkram at tripelspark.de> wrote: > > > Thx! > > It seems these processes are in state "dovecot/imap-login [1 pre-login]". > > Concerning logs, the only thing that seems suspicious to me is: > > Jan 31 00:33:05 static dovecot: imap-login: Disconnected (no auth > attempts in 5 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS > handshaking: Connection closed, session=<QD/tiia6aKlb6BxS> > Jan 31 00:33:05 static dovecot: imap-login: Disconnected (no auth > attempts in 0 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS > handshaking: SSL_accept() failed: error:1408F09C:SSL > routines:ssl3_get_record:http request, session=<OCruiia6fstb6BxS> > Jan 31 00:33:06 static dovecot: imap-login: Disconnected (no auth > attempts in 0 secs): user=<>, rip=91.232.28.82, lip=78.46.17.21, TLS > handshaking: SSL_accept() failed: error:1408F09C:SSL > routines:ssl3_get_record:http request, session=<SaPviia6HMxb6BxS> > > The IPs in question are not our own IPs. > > Since restarting (about 45 minutes), I have about a dozen of the > "Disconnected (no auth attempts" and exactly 13 of the pre-login > processes. In fact, the number of pre-login processes just jumped by 2 > and the log just shows 2 new "Disconnected (no auth attempts in 0 secs)" > > This might have something to do with it. > > Version is 2.3.4.1. It's a production system, I'd like to avoid having > to compile my own version of dovecot unless there's no way around it. > > Greetings, > Wolfgang > > On 2/5/21 10:51 AM, Aki Tuomi wrote: > > Can you set > > > > verbose_proctitle = yes > > > > this should provide more information what the process is up to. > > > > Can you also check your logs? > > > > Aki > > > >> On 05/02/2021 11:46 Wolfgang <adminkram at tripelspark.de> wrote: > >> > >> > >> Hi, > >> > >> Sorry, the problem is back! Not solved, again no change except that I > >> lowered the limits again and restarted dovecot. Here is what it looks like: > >> > >> lsof -a -i4 -i6 -itcp | fgrep imap-logi | wc > >> 9 > >> > >> --> There are 9 TCP connections to imap-login. > >> > >> ps aux | fgrep imap-login | wc > >> 81 > >> ps aux | fgrep imap | wc > >> 90 > >> > >> --> There are 90-81 = 9 IMAP worker processes (OK) and 81 imap-login > >> processes (not OK). Thunderbird cannot connect again. > >> > >> ps auxf | fgrep dove > >> root 28118 0.0 0.0 4200 2752 ? Ss Feb03 0:02 > >> /usr/sbin/dovecot -F > >> dovecot 28138 0.0 0.0 4176 2224 ? S Feb03 0:01 \_ > >> dovecot/anvil > >> root 28139 0.0 0.0 4172 2436 ? S Feb03 0:00 \_ > >> dovecot/log > >> root 28140 0.0 0.0 6764 4636 ? S Feb03 0:05 \_ > >> dovecot/config > >> dovecot 28143 0.0 0.0 5360 3584 ? S Feb03 0:01 \_ > >> dovecot/stats > >> dovenull 28206 0.0 0.0 8200 4652 ? S Feb03 0:02 \_ > >> dovecot/imap-login > >> USER2 28207 0.0 0.0 6356 3988 ? S Feb03 0:02 \_ > >> dovecot/imap > >> dovenull 28234 0.0 0.0 8200 4712 ? S Feb03 0:02 \_ > >> dovecot/imap-login > >> USER1 28235 0.0 0.0 6356 2924 ? S Feb03 0:02 \_ > >> dovecot/imap > >> dovenull 28275 0.0 0.0 8200 4716 ? S Feb03 0:02 \_ > >> dovecot/imap-login > >> USER1 28276 0.0 0.0 9416 7308 ? S Feb03 0:03 \_ > >> dovecot/imap > >> dovenull 19673 0.0 0.0 8212 6380 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> USER3 19674 0.0 0.0 14220 7680 ? S Feb04 0:01 \_ > >> dovecot/imap > >> dovenull 21688 0.0 0.0 8200 6416 ? S Feb04 0:01 \_ > >> dovecot/imap-login > >> USER2 21690 0.0 0.0 9604 8504 ? S Feb04 0:01 \_ > >> dovecot/imap > >> dovenull 22398 0.0 0.0 8200 6440 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 22400 0.0 0.0 8200 6384 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 22593 0.0 0.0 8200 6292 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 22595 0.0 0.0 8200 6312 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 22814 0.0 0.0 8200 6324 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 22816 0.0 0.0 8200 6312 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23026 0.0 0.0 8200 6384 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23028 0.0 0.0 8200 6340 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> .......(skipped some lines of imap-login)........ > >> dovenull 23179 0.0 0.0 8200 6412 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23181 0.0 0.0 8200 6368 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23421 0.0 0.0 8200 6284 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23423 0.0 0.0 8200 6412 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23611 0.0 0.0 8200 6380 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23613 0.0 0.0 8200 6296 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23797 0.0 0.0 8200 6464 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 23799 0.0 0.0 8200 6296 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 24029 0.0 0.0 8200 6300 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 24031 0.0 0.0 8200 6188 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 24205 0.0 0.0 8200 6340 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 24207 0.0 0.0 8200 6320 ? S Feb04 0:00 \_ > >> dovecot/imap-login > >> dovenull 5628 0.0 0.0 8212 6408 ? S 08:59 0:00 \_ > >> dovecot/imap-login > >> USER1 5629 0.0 0.0 7844 6460 ? S 08:59 0:00 \_ > >> dovecot/imap > >> optores 5630 0.0 0.0 6356 4444 ? S 08:59 0:00 \_ > >> dovecot/imap > >> USER1 5631 0.0 0.0 6372 4568 ? S 08:59 0:00 \_ > >> dovecot/imap > >> dovenull 6373 0.0 0.0 8200 6224 ? S 09:43 0:00 \_ > >> dovecot/imap-login > >> USER1 6375 0.0 0.0 7052 5900 ? S 09:43 0:00 \_ > >> dovecot/imap > >> > >> The config is the same as last time except for this: > >> > >> auth_worker_max_count = 100 > >> default_process_limit = 80 > >> > >> Which should be more than enough. > >> > >> Any ideas? > >> Wolfgang > >> > >> On 2/3/21 8:19 PM, Wolfgang wrote: > >>> Hi, > >>> > >>>> But as Aki said, doveconf -n is crucial, especially since you upgraded > >>> from an older version. > >>>> > >>> > >>> Thank you for your response. Unfortunately, I missed the first e-mail a > >>> few days ago. > >>> > >>> Interestingly it does no longer happen since a few days. We're seeing > >>> one IMAP and one IMAP-LOGIN process per connection now which is the > >>> expected behavior. > >>> > >>> It's completely unclear to me why this does not longer happen now. > >>> > >>> Anyway, here's the doveconf output in case you spot something. > >>> > >>> Thank you, > >>> Wolfgang > >>> > >>> # 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf > >>> # Pigeonhole version 0.5.4 () > >>> # OS: Linux 4.19.0-11-amd64 x86_64 Debian 10.7 > >>> # Hostname: static...... > >>> auth_mechanisms = scram-sha-1 digest-md5 cram-md5 plain > >>> auth_worker_max_count = 300 > >>> default_process_limit = 200 > >>> first_valid_uid = 1000 > >>> hostname = ....... > >>> log_timestamp = "%Y-%m-%d %H:%M:%S " > >>> mail_location = maildir:~/Maildir > >>> mail_plugins = quota acl > >>> mail_privileged_group = mail > >>> mail_server_admin = postmaster at ....... > >>> managesieve_notify_capability = mailto > >>> managesieve_sieve_capability = fileinto reject envelope > >>> encoded-character vacation subaddress comparator-i;ascii-numeric > >>> relational regex imap4flags copy include variables body enotify > >>> environment mailbox date index ihave duplicate mime foreverypart > >>> extracttext editheader > >>> namespace inbox { > >>> inbox = yes > >>> location > >>> mailbox Drafts { > >>> special_use = \Drafts > >>> } > >>> mailbox Junk { > >>> special_use = \Junk > >>> } > >>> mailbox Sent { > >>> special_use = \Sent > >>> } > >>> mailbox "Sent Messages" { > >>> special_use = \Sent > >>> } > >>> mailbox Trash { > >>> special_use = \Trash > >>> } > >>> prefix > >>> separator = / > >>> type = private > >>> } > >>> namespace zzzzz { > >>> list = children > >>> location = maildir:%%h/Maildir-xxx:INDEX=~/index_shared/%%u > >>> prefix = shared/%%u/ > >>> separator = / > >>> subscriptions = no > >>> type = shared > >>> } > >>> passdb { > >>> args = /etc/dovecot/shadow > >>> driver = passwd-file > >>> } > >>> plugin { > >>> acl = vfile > >>> acl_shared_dict = file:/var/mail/shared-%d/shared-mailboxes > >>> quota = maildir:User quota > >>> quota_rule = *:storage=1G > >>> quota_warning = storage=90%% quota-warning 90 %u > >>> sieve = file:~/sieve;active=~/dovecot.sieve > >>> sieve_extensions = +editheader > >>> } > >>> postmaster_address = postmaster at xxxxxxx.de > >>> protocols = " imap sieve sieve" > >>> service auth-worker { > >>> chroot = yes > >>> user = $default_internal_user > >>> } > >>> service auth { > >>> unix_listener /var/spool/postfix/private/auth { > >>> group = postfix > >>> mode = 0660 > >>> user = postfix > >>> } > >>> } > >>> service imap-login { > >>> vsz_limit = 64 M > >>> } > >>> service managesieve-login { > >>> inet_listener sieve { > >>> port = 4190 > >>> } > >>> inet_listener sieve_deprecated { > >>> port = 2000 > >>> } > >>> } > >>> ssl_cert = </etc/letsencrypt/live/..../fullchain.pem > >>> ssl_client_ca_dir = /etc/ssl/certs > >>> ssl_dh = # hidden, use -P to show it > >>> ssl_key = # hidden, use -P to show it > >>> userdb { > >>> args = /etc/dovecot/passwd > >>> default_fields = quota_rule=*:storage=1G > >>> driver = passwd-file > >>> } > >>> protocol lda { > >>> mail_plugins = quota acl sieve > >>> } > >>> protocol imap { > >>> mail_max_userip_connections = 32 > >>> mail_plugins = quota acl imap_quota imap_acl > >>> } > >>> > >