Thousands of SSL certificates stalls new logins during reload - problem with Dovecot config process
Felipe Gasper
felipe at felipegasper.com
Fri Sep 2 12:52:49 UTC 2022
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
>
More information about the dovecot
mailing list