thr3ads.net - dovecot - Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process [Sep 2022]

If this information is useful, please help other people find it:
Share via:

Bartosz Kwitniewski

2022-Sep-02 12:44 UTC

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

Hello,

I'm running a dovecot 2.3.19.1 server that has around 6000 SSL 
certificates in separate config files, each containing:
local_name "domain" {
     ssl_cert = ...
     ssl_key = ...
}
When new certificate is added, dovecot is reloaded (around 20 times a 
day). When dovecot is being reloaded, users are unable to log in for 
around 30 seconds.

The main problem here seems to be that during reload, new config process 
is immediately designated as the one serving config requests and then it 
starts parsing config files, which takes around 20-30 seconds. If it 
would parse config files first, and only then would become a new process 
for serving config requests, then it would probably solve the problem. 
Or perhaps there is a better way to load new certificates or a way to 
optimize?

There is another problem with config process and shutdown_clients=no. We 
do not want to disconnect users during reload, because e.g. Thunderbird 
displays a popup that server is shutting down. When there are long 
lasting IMAP connections from Google and other services that aggregate 
e-mail, old config process is not being killed. Because config process 
with ~6000 certificates is using ~1 GB of RAM, it can quickly rise to 20 
GB of memory used. This is not a big issue however, because we have 
created a task that kills old processes, but there could be a built-in 
mechanism to solve that problem.

I have created minimal configuration and scripts to recreate problem. 
Reproduction steps below.

Configuration (doveadm config -n):
=========# 2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf
# OS: Linux 4.18.0-372.9.1.1.lve.el8.x86_64 x86_64 CloudLinux release 
8.6 (Leonid Kadenyuk)
# Hostname: -
auth_mechanisms = plain login
default_client_limit = 12288
default_process_limit = 2048
default_vsz_limit = 1 G
first_valid_uid = 1000
mail_location = maildir:~/mail
mbox_write_locks = fcntl
namespace inbox {
   inbox = yes
   location    mailbox Drafts {
     special_use = \Drafts
   }
   mailbox Sent {
     special_use = \Sent
   }
   mailbox "Sent Messages" {
     special_use = \Sent
   }
   mailbox Trash {
     special_use = \Trash
   }
   prefix }
passdb {
   args = scheme=CRYPT username_format=%u /etc/dovecot/users
   driver = passwd-file
}
service auth-worker {
   user = $default_internal_user
}
service auth {
   user = $default_internal_user
}
service config {
   vsz_limit = 4 G
}
service imap-login {
   process_min_avail = 20
   service_count = 1
}
service imap {
   process_limit = 4096
}
service pop3-login {
   process_min_avail = 20
   service_count = 1
}
service pop3 {
   process_limit = 512
}
shutdown_clients = no
ssl_cert = </etc/dovecot/certs/example.org.crt
ssl_cipher_list = 
ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:DHE-DSS-AES128-GCM-SHA256:DHE-DSS-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-DSS-AES128-SHA256:DHE-DSS-AES256-SHA256:DHE-DSS-AES128-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA:ECDH-ECDSA-AES128-GCM-SHA256:ECDH-ECDSA-AES256-GCM-SHA384:ECDH-RSA-AES128-GCM-SHA256:ECDH-RSA-AES256-GCM-SHA384:ECDH-ECDSA-AES128-SHA256:ECDH-ECDSA-AES256-SHA384:ECDH-ECDSA-AES128-SHA:ECDH-RSA-AES128-SHA256:ECDH-RSA-AES256-SHA384:ECDH-RSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-CHACHA20-POLY1305
ssl_dh = </etc/dovecot/dh.pem
ssl_key = </etc/dovecot/certs/example.org.key
ssl_options = no_compression
ssl_prefer_server_ciphers = yes
userdb {
   args = username_format=%u /etc/dovecot/users
   driver = passwd-file
}
verbose_proctitle = yes
protocol imap {
   mail_max_userip_connections = 2048
}
protocol pop3 {
   mail_max_userip_connections = 2048
}
local_name domain4587.example.org mail.domain4587.example.org {
   ssl_cert = </etc/dovecot/certs/domain4587.example.org.crt
   ssl_key = </etc/dovecot/certs/domain4587.example.org.key
}
local_name domain4588.example.org mail.domain4588.example.org {
   ssl_cert = </etc/dovecot/certs/domain4588.example.org.crt
   ssl_key = </etc/dovecot/certs/domain4588.example.org.key
}
(...) 5000 certificates goes here
=========
/etc/dovecot/users:
=========user at
domain1.example.org:{SHA512-CRYPT}$6$...:1000:1000::/home/test/mail/domain1.example.org/user::
user at
domain2.example.org:{SHA512-CRYPT}$6$...:1000:1000::/home/test/mail/domain2.example.org/user::
(...) 5000 users goes here, but one should be enough for testing.
=========
Log file from dovecot reload:
=========Sep 02 12:37:24 dovecot[264040]: imap-login: Login: 
user=<user at domain1.example.org>, method=PLAIN, rip=127.0.0.1, 
lip=127.0.0.1, mpid=264964, TLS, session=<eQXGUK/ngJJ/AAAB>
Sep 02 12:37:24 dovecot[264040]: 
imap(user at domain1.example.org)<264964><eQXGUK/ngJJ/AAAB>:
Disconnected:
Logged out in=25 out=782 deleted=0 expunged=0 trashed=0 hdr_count=0 
hdr_bytes=0 body_count=0 body_bytes=0
Sep 02 12:37:25 systemd[1]: Reloading Dovecot IMAP/POP3 email server.
Sep 02 12:37:26 dovecot[263234]: master: Warning: SIGHUP received - 
reloading configuration
Sep 02 12:37:36 dovecot[263234]: master: Error: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket
Sep 02 12:37:36 systemd[1]: Reloaded Dovecot IMAP/POP3 email server.
Sep 02 12:37:36 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: stat(/usr/local/var/run/dovecot/config) 
failed: No such file or directory (path is from CONFIG_FILE environment)
Sep 02 12:37:36 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: stat(/usr/local/var/run/dovecot/config) 
failed: No such file or directory (path is from CONFIG_FILE environment)
Sep 02 12:37:42 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: stat(/usr/local/var/run/dovecot/config) 
failed: No such file or directory (path is from CONFIG_FILE environment)
Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket (path is from CONFIG_FILE environment)
Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket (path is from CONFIG_FILE environment)
Sep 02 12:37:46 dovecot[263234]: master: Error: service(imap-login): 
command startup failed, throttling for 2.000 secs
Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket (path is from CONFIG_FILE environment)
Sep 02 12:37:47 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: stat(/usr/local/var/run/dovecot/config) 
failed: No such file or directory (path is from CONFIG_FILE environment)
Sep 02 12:37:47 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket (path is from CONFIG_FILE environment)
Sep 02 12:37:48 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: stat(/usr/local/var/run/dovecot/config) 
failed: No such file or directory (path is from CONFIG_FILE environment)
Sep 02 12:37:48 dovecot[264040]: imap-login: Fatal: Error reading 
configuration: read(/usr/local/var/run/dovecot/config) failed: 
read(size=8192) failed: Interrupted system call - Also failed to read 
config by executing doveconf: /usr/local/var/run/dovecot/config is a 
UNIX socket (path is from CONFIG_FILE environment)
Sep 02 12:37:48 dovecot[263234]: master: Error: service(imap-login): 
command startup failed, throttling for 4.000 secs
Sep 02 12:37:49 dovecot[264040]: imap-login: Disconnected: Connection 
closed: read(size=737) failed: Connection reset by peer (no auth 
attempts in 5 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, TLS 
handshaking: read(size=737) failed: Connection reset by peer, 
session=<eNlHUq/njJJ/AAAB>
Sep 02 12:37:49 dovecot[264040]: imap-login: Login: 
user=<user at domain1.example.org>, method=PLAIN, rip=127.0.0.1, 
lip=127.0.0.1, mpid=265059, TLS, session=<duBHUq/njpJ/AAAB>
Sep 02 12:37:49 dovecot[264040]: 
imap(user at domain1.example.org)<265059><duBHUq/njpJ/AAAB>:
Disconnected:
Logged out in=25 out=790 deleted=0 expunged=0 trashed=0 hdr_count=0 
hdr_bytes=0 body_count=0 body_bytes=0
=========
Script for testing login:
========== test-imap.expect =========#!/usr/bin/expect -f

set timeout 5
expect_before {
     timeout { puts "Error: Timeout"; exit 1 }
     eof     { puts "Error: EOF";     exit 1 }
}
log_user 0

spawn openssl s_client -connect 127.0.0.1:993
expect "* OK"
send -- "C1 LOGIN user at domain1.example.org PASSWORD\n"
expect "C1 OK"
send -- "C2 SELECT Inbox\n"
expect "C2 OK"
send -- "C3 LOGOUT\n"
expect "C3 OK"
expect eof
=========
Script for testing long lasting login:
========== test-imap-long.expect =========#!/usr/bin/expect -f

set timeout -1
expect_before {
     timeout { puts "Error: Timeout"; exit 1 }
     eof     { puts "Error: EOF";     exit 1 }
}
log_user 0

spawn openssl s_client -connect 127.0.0.1:993
expect "* OK"
send -- "C1 LOGIN user at domain1.example.org PASSWORD\n"
expect "C1 OK"
send -- "C2 SELECT Inbox\n"
expect "C2 OK"
=========
Reproduction steps (I can attach full package for testing with 5000 
self-signed certificates):
1. Start dovecot 2.3.19.1 with 5000 certificates in configuration files 
using config above.
2. Start test-imap.expect on another console, like that:
while true; do date_now=$(date "+%Y-%m-%d %H:%M:%S"); echo -n 
"[$date_now] Test: "; ./imap-test.expect && echo
"OK"; sleep 1; done
3. Reload dovecot.
4. Check logs and test-imap.expect output.

Reproduction steps for config process not being terminated:
1. Start dovecot 2.3.19.1 using config above.
2. Start test-imap-long.expect (the second script) on another console.
3. Reload dovecot.
4. Start another test-imap-long.expect on another console.
5. Reload dovecot.
6. Check process list for dovecot config.

Best regards,
-- 
Bartosz Kwitniewski

Felipe Gasper

2022-Sep-02 12:52 UTC

head link

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

For hosting environments--where TLS certs can change hundreds of times in a
matter of minutes--it would be a boon for Dovecot to load those certificates
dynamically rather than all at once.

Pure-FTPd implements a nice solution to this: a standalone service that fetches
TLS certificates & keys. Documented here:

https://github.com/jedisct1/pure-ftpd/blob/9d25440e5b5283fbeca94dd0595aa6672c3f8428/README.TLS#L161

-FG

> On Sep 2, 2022, at 08:44, Bartosz Kwitniewski <zerg-dovecot at
uid0.pl> wrote:
> 
> Hello,
> 
> I'm running a dovecot 2.3.19.1 server that has around 6000 SSL
certificates in separate config files, each containing:
> local_name "domain" {
>    ssl_cert = ...
>    ssl_key = ...
> }
> When new certificate is added, dovecot is reloaded (around 20 times a day).
When dovecot is being reloaded, users are unable to log in for around 30
seconds.
> 
> The main problem here seems to be that during reload, new config process is
immediately designated as the one serving config requests and then it starts
parsing config files, which takes around 20-30 seconds. If it would parse config
files first, and only then would become a new process for serving config
requests, then it would probably solve the problem. Or perhaps there is a better
way to load new certificates or a way to optimize?
> 
> There is another problem with config process and shutdown_clients=no. We do
not want to disconnect users during reload, because e.g. Thunderbird displays a
popup that server is shutting down. When there are long lasting IMAP connections
from Google and other services that aggregate e-mail, old config process is not
being killed. Because config process with ~6000 certificates is using ~1 GB of
RAM, it can quickly rise to 20 GB of memory used. This is not a big issue
however, because we have created a task that kills old processes, but there
could be a built-in mechanism to solve that problem.
> 
> I have created minimal configuration and scripts to recreate problem.
Reproduction steps below.
> 
> Configuration (doveadm config -n):
> =========> # 2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf
> # OS: Linux 4.18.0-372.9.1.1.lve.el8.x86_64 x86_64 CloudLinux release 8.6
(Leonid Kadenyuk)
> # Hostname: -
> auth_mechanisms = plain login
> default_client_limit = 12288
> default_process_limit = 2048
> default_vsz_limit = 1 G
> first_valid_uid = 1000
> mail_location = maildir:~/mail
> mbox_write_locks = fcntl
> namespace inbox {
>  inbox = yes
>  location >  mailbox Drafts {
>    special_use = \Drafts
>  }
>  mailbox Sent {
>    special_use = \Sent
>  }
>  mailbox "Sent Messages" {
>    special_use = \Sent
>  }
>  mailbox Trash {
>    special_use = \Trash
>  }
>  prefix > }
> passdb {
>  args = scheme=CRYPT username_format=%u /etc/dovecot/users
>  driver = passwd-file
> }
> service auth-worker {
>  user = $default_internal_user
> }
> service auth {
>  user = $default_internal_user
> }
> service config {
>  vsz_limit = 4 G
> }
> service imap-login {
>  process_min_avail = 20
>  service_count = 1
> }
> service imap {
>  process_limit = 4096
> }
> service pop3-login {
>  process_min_avail = 20
>  service_count = 1
> }
> service pop3 {
>  process_limit = 512
> }
> shutdown_clients = no
> ssl_cert = </etc/dovecot/certs/example.org.crt
> ssl_cipher_list =
ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:DHE-DSS-AES128-GCM-SHA256:DHE-DSS-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-DSS-AES128-SHA256:DHE-DSS-AES256-SHA256:DHE-DSS-AES128-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA:ECDH-ECDSA-AES128-GCM-SHA256:ECDH-ECDSA-AES256-GCM-SHA384:ECDH-RSA-AES128-GCM-SHA256:ECDH-RSA-AES256-GCM-SHA384:ECDH-ECDSA-AES128-SHA256:ECDH-ECDSA-AES256-SHA384:ECDH-ECDSA-AES128-SHA:ECDH-RSA-AES128-SHA256:ECDH-RSA-AES256-SHA384:ECDH-RSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-CHACHA20-POLY1305
> ssl_dh = </etc/dovecot/dh.pem
> ssl_key = </etc/dovecot/certs/example.org.key
> ssl_options = no_compression
> ssl_prefer_server_ciphers = yes
> userdb {
>  args = username_format=%u /etc/dovecot/users
>  driver = passwd-file
> }
> verbose_proctitle = yes
> protocol imap {
>  mail_max_userip_connections = 2048
> }
> protocol pop3 {
>  mail_max_userip_connections = 2048
> }
> local_name domain4587.example.org mail.domain4587.example.org {
>  ssl_cert = </etc/dovecot/certs/domain4587.example.org.crt
>  ssl_key = </etc/dovecot/certs/domain4587.example.org.key
> }
> local_name domain4588.example.org mail.domain4588.example.org {
>  ssl_cert = </etc/dovecot/certs/domain4588.example.org.crt
>  ssl_key = </etc/dovecot/certs/domain4588.example.org.key
> }
> (...) 5000 certificates goes here
> =========> 
> /etc/dovecot/users:
> =========> user at
domain1.example.org:{SHA512-CRYPT}$6$...:1000:1000::/home/test/mail/domain1.example.org/user::
> user at
domain2.example.org:{SHA512-CRYPT}$6$...:1000:1000::/home/test/mail/domain2.example.org/user::
> (...) 5000 users goes here, but one should be enough for testing.
> =========> 
> Log file from dovecot reload:
> =========> Sep 02 12:37:24 dovecot[264040]: imap-login: Login:
user=<user at domain1.example.org>, method=PLAIN, rip=127.0.0.1,
lip=127.0.0.1, mpid=264964, TLS, session=<eQXGUK/ngJJ/AAAB>
> Sep 02 12:37:24 dovecot[264040]: imap(user at
domain1.example.org)<264964><eQXGUK/ngJJ/AAAB>: Disconnected: Logged
out in=25 out=782 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0
body_count=0 body_bytes=0
> Sep 02 12:37:25 systemd[1]: Reloading Dovecot IMAP/POP3 email server.
> Sep 02 12:37:26 dovecot[263234]: master: Warning: SIGHUP received -
reloading configuration
> Sep 02 12:37:36 dovecot[263234]: master: Error: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket
> Sep 02 12:37:36 systemd[1]: Reloaded Dovecot IMAP/POP3 email server.
> Sep 02 12:37:36 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: stat(/usr/local/var/run/dovecot/config) failed: No such file or
directory (path is from CONFIG_FILE environment)
> Sep 02 12:37:36 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: stat(/usr/local/var/run/dovecot/config) failed: No such file or
directory (path is from CONFIG_FILE environment)
> Sep 02 12:37:42 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: stat(/usr/local/var/run/dovecot/config) failed: No such file or
directory (path is from CONFIG_FILE environment)
> Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket (path is from
CONFIG_FILE environment)
> Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket (path is from
CONFIG_FILE environment)
> Sep 02 12:37:46 dovecot[263234]: master: Error: service(imap-login):
command startup failed, throttling for 2.000 secs
> Sep 02 12:37:46 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket (path is from
CONFIG_FILE environment)
> Sep 02 12:37:47 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: stat(/usr/local/var/run/dovecot/config) failed: No such file or
directory (path is from CONFIG_FILE environment)
> Sep 02 12:37:47 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket (path is from
CONFIG_FILE environment)
> Sep 02 12:37:48 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: stat(/usr/local/var/run/dovecot/config) failed: No such file or
directory (path is from CONFIG_FILE environment)
> Sep 02 12:37:48 dovecot[264040]: imap-login: Fatal: Error reading
configuration: read(/usr/local/var/run/dovecot/config) failed: read(size=8192)
failed: Interrupted system call - Also failed to read config by executing
doveconf: /usr/local/var/run/dovecot/config is a UNIX socket (path is from
CONFIG_FILE environment)
> Sep 02 12:37:48 dovecot[263234]: master: Error: service(imap-login):
command startup failed, throttling for 4.000 secs
> Sep 02 12:37:49 dovecot[264040]: imap-login: Disconnected: Connection
closed: read(size=737) failed: Connection reset by peer (no auth attempts in 5
secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, TLS handshaking:
read(size=737) failed: Connection reset by peer,
session=<eNlHUq/njJJ/AAAB>
> Sep 02 12:37:49 dovecot[264040]: imap-login: Login: user=<user at
domain1.example.org>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1,
mpid=265059, TLS, session=<duBHUq/njpJ/AAAB>
> Sep 02 12:37:49 dovecot[264040]: imap(user at
domain1.example.org)<265059><duBHUq/njpJ/AAAB>: Disconnected: Logged
out in=25 out=790 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0
body_count=0 body_bytes=0
> =========> 
> Script for testing login:
> ========== test-imap.expect =========> #!/usr/bin/expect -f
> 
> set timeout 5
> expect_before {
>    timeout { puts "Error: Timeout"; exit 1 }
>    eof     { puts "Error: EOF";     exit 1 }
> }
> log_user 0
> 
> spawn openssl s_client -connect 127.0.0.1:993
> expect "* OK"
> send -- "C1 LOGIN user at domain1.example.org PASSWORD\n"
> expect "C1 OK"
> send -- "C2 SELECT Inbox\n"
> expect "C2 OK"
> send -- "C3 LOGOUT\n"
> expect "C3 OK"
> expect eof
> =========> 
> Script for testing long lasting login:
> ========== test-imap-long.expect =========> #!/usr/bin/expect -f
> 
> set timeout -1
> expect_before {
>    timeout { puts "Error: Timeout"; exit 1 }
>    eof     { puts "Error: EOF";     exit 1 }
> }
> log_user 0
> 
> spawn openssl s_client -connect 127.0.0.1:993
> expect "* OK"
> send -- "C1 LOGIN user at domain1.example.org PASSWORD\n"
> expect "C1 OK"
> send -- "C2 SELECT Inbox\n"
> expect "C2 OK"
> =========> 
> Reproduction steps (I can attach full package for testing with 5000
self-signed certificates):
> 1. Start dovecot 2.3.19.1 with 5000 certificates in configuration files
using config above.
> 2. Start test-imap.expect on another console, like that:
> while true; do date_now=$(date "+%Y-%m-%d %H:%M:%S"); echo -n
"[$date_now] Test: "; ./imap-test.expect && echo
"OK"; sleep 1; done
> 3. Reload dovecot.
> 4. Check logs and test-imap.expect output.
> 
> Reproduction steps for config process not being terminated:
> 1. Start dovecot 2.3.19.1 using config above.
> 2. Start test-imap-long.expect (the second script) on another console.
> 3. Reload dovecot.
> 4. Start another test-imap-long.expect on another console.
> 5. Reload dovecot.
> 6. Check process list for dovecot config.
> 
> Best regards,
> -- 
> Bartosz Kwitniewski
>

Arkadiusz Miśkiewicz

2022-Sep-05 12:16 UTC

head link

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

On 2.09.2022 14:44, Bartosz Kwitniewski wrote:> Hello,
> 
> I'm running a dovecot 2.3.19.1 server that has around 6000 SSL 
> certificates in separate config files, each containing:
> local_name "domain" {
>  ??? ssl_cert = ...
>  ??? ssl_key = ...
> }
> When new certificate is added, dovecot is reloaded (around 20 times a 
> day). When dovecot is being reloaded, users are unable to log in for 
> around 30 seconds.
Unfortunately it's known for ages that dovecot is not capable of 
handling thousands of certificates in a sane way.

There were some ideas which were never implemented:

https://dovecot.org/list/dovecot/2016-October/105858.html

( https://dovecot.org/list/dovecot/2016-October/105855.html )

-- 
Arkadiusz Mi?kiewicz, arekm / ( maven.pl | pld-linux.org )

dovecot - Sep 2022 - Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process

Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process