Multi-thread cyrus delayed forking of imapd processes after connecting to master listener

Fri May 19 06:45:30 EDT 2017

Have you tried stracing one of the imap processes that is slow to see where the delay is?

On May 19, 2017 6:48:36 AM ADT, Michael Hieb <michael.hieb at celoso.net> wrote:
>Apologies for long post, most of it is configuration details.
>
>I have recently changed from a single threaded cyrus server in which 
>multiple domains were overloaded on one listener as multiple virtual 
>domains to a multiple threaded cyrus server in which multiple domains 
>are listened for on separate ip addresses with separate configurations.
>
>The primary motivation was to have separate tls certificates for each 
>domain. The problem is that I can connect to cyrus listener on all 
>ip/ports for all domains, but while one of them will fork immediately 
>and respond with a banner, the others will delay for a period of time 
>from a few seconds to a minute or so before forking and responding with
>
>a banner. With the same setup, I change to a single threaded cyrus 
>server to listen on all ip/ports then I get an immediate response on 
>all, but of course I do not get the separate tls certificate or 
>configuration. It is replicable that switching between the single 
>threaded and multiple threaded configuration triggers the problem. I 
>have searched the logs and the mail-lists and found nothing that seems 
>related.
>
>Question: why does switching to multiple threaded cyrus server trigger 
>delayed forking of imapd processes after connecting to master listener?
>
>On listener which responds immediately (as expected) I get this:
>
>user at somehost:~> telnet imap.domain1.com 143
>Trying 192.168.110.171...
>Connected to imap.domain1.com.
>Escape character is '^]'.
>* OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE STARTTLS AUTH=GSS-SPNEGO 
>AUTH=GSSAPI AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN
>SASL-IR] 
>imap.domain1.com Cyrus IMAP v2.4.18 server ready
>
>On listener with delay, I get this (and process hangs for many seconds 
>or even a minute or two):
>
>user at somehost:~> telnet imap.domain2.com 143
>Trying 192.168.110.171...
>Connected to imap.domain2.com.
>Escape character is '^]'.
>
>The domain for which the listener responds and the one for which it 
>delays seems to change and be random as far as I can tell.
>
>There is nothing in the log journal that looks different from when we 
>connect and get a for and when we connect and get a delay.
>
>May 19 09:44:31 MAILSERVER master[13762]: about to exec 
>/usr/lib/cyrus/bin/imapd
>May 19 09:44:31 MAILSERVER imap[13762]: executed
>May 19 09:44:31 MAILSERVER imap[13762]: IOERROR: opening 
>/var/lib/imap/user_deny.db: No such file or directory
>
>and once imapd forks and banner is generated
>
>May 19 09:46:45 MAILSERVER imap[13814]: accepted connection
>
>Here are the configuration details:
>
>I run cyrus 2.4.18-3.6 on openSuSE Leap 42.2 Linux MAILSERVER 
>4.4.62-18.6-default #1 SMP Fri Apr 21 16:14:48 UTC 2017 (84f9824)
>x86_64 
>x86_64 x86_64 GNU/Linux.
>
>Here is my (sanitized) cyrus.conf and one imapd.conf (they all look 
>alike except for certificate and domain specifics).
>
>MAILSERVER:~ # cat /etc/cyrus.conf
>START {
># do not delete this entry!
>recover cmd="ctl_cyrusdb -r"
>
># this is only necessary if using idled for IMAP IDLE
>idled cmd="idled"
>}
>
># UNIX sockets start with a slash and are put into /var/lib/imap/socket
>SERVICES {
># add or remove based on preferences
>#imap cmd="imapd" listen="imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain1.com.conf " 
>listen="192.168.171.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain1.com.conf " 
>listen="192.168.110.171:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain2.com.conf " 
>listen="192.168.172.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain2.com.conf " 
>listen="192.168.110.172:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain3.com.conf " 
>listen="192.168.174.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain3.com.conf " 
>listen="192.168.110.174:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain4.com.conf " 
>listen="192.168.175.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain4.com.conf " 
>listen="192.168.110.175:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain5.com.conf " 
>listen="192.168.176.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain5.com.conf " 
>listen="192.168.110.176:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain6.com.conf " 
>listen="192.168.177.4:imap" maxchild=-1 maxforkrate=100
>imap cmd="imapd -C /etc/imapd.domain6.com.conf " 
>listen="192.168.110.177:imap" maxchild=-1 maxforkrate=100
>
>#imaps cmd="imapd -s" listen="imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain1.com.conf -s " 
>listen="192.168.171.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain1.com.conf -s " 
>listen="192.168.110.171:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain2.com.conf -s " 
>listen="192.168.172.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain2.com.conf -s " 
>listen="192.168.110.172:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain3.com.conf -s " 
>listen="192.168.174.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain3.com.conf -s " 
>listen="192.168.110.174:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain4.com.conf -s " 
>listen="192.168.175.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain4.com.conf -s " 
>listen="192.168.110.175:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain5.com.conf -s " 
>listen="192.168.176.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain5.com.conf -s " 
>listen="192.168.110.176:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain6.com.conf -s " 
>listen="192.168.177.4:imaps" maxchild=-1 maxforkrate=100
>imaps cmd="imapd -C /etc/imapd.domain6.com.conf -s " 
>listen="192.168.110.177:imaps" maxchild=-1 maxforkrate=100
>
>#pop3 cmd="pop3d" listen="pop3"
>#pop3s cmd="pop3d -s" listen="pop3s"
>#sieve cmd="timsieved" listen="sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain1.com.conf" 
>listen="192.168.171.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain1.com.conf" 
>listen="192.168.110.171:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain2.com.conf" 
>listen="192.168.172.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain2.com.conf" 
>listen="192.168.110.172:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain3.com.conf" 
>listen="192.168.174.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain3.com.conf" 
>listen="192.168.110.174:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain4.com.conf" 
>listen="192.168.175.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain4.com.conf" 
>listen="192.168.110.175:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain5.com.conf" 
>listen="192.168.176.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain5.com.conf" 
>listen="192.168.110.176:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain6.com.conf" 
>listen="192.168.177.4:sieve" maxchild=-1 maxforkrate=100
>sieve cmd="timsieved -C /etc/imapd.domain6.com.conf" 
>listen="192.168.110.177:sieve" maxchild=-1 maxforkrate=100
>
>#ptloader cmd="ptloader" listen="/var/lib/imap/ptclient/ptsock"
>
># at least one LMTP is required for delivery
>lmtp cmd="lmtpd -a" listen="mail.domain1.com:lmtp" maxchild=-1 
>maxforkrate=100
>lmtp cmd="lmtpd -a" listen="mail.domain2.com:lmtp" maxchild=-1 
>maxforkrate=100
>lmtp cmd="lmtpd -a" listen="mail.domain3.com:lmtp" maxchild=-1 
>maxforkrate=100
>lmtp cmd="lmtpd -a" listen="mail.domain4.com:lmtp" maxchild=-1 
>maxforkrate=100
>lmtp cmd="lmtpd -a" listen="mail.domain5.com:lmtp" maxchild=-1 
>maxforkrate=100
>lmtp cmd="lmtpd -a" listen="mail.domain6.com:lmtp" maxchild=-1 
>maxforkrate=100
>#lmtpunix cmd="lmtpd" listen="/var/lib/imap/socket/lmtp"
>
># this is only necessary if using notifications
>#notify cmd="notifyd" listen="/var/lib/imap/socket/notify" proto="udp"
>}
>
>EVENTS {
># this is required
>checkpoint cmd="ctl_cyrusdb -c" period=30
>
># this is only necessary if using duplicate delivery suppression,
># Sieve or NNTP
>duplicateprune cmd="cyr_expire -E 3" at=0400
>
># Expire data older then 69 days. Two full months of 31 days
># each includes two full backup cycles, plus 1 week margin
># because we run our full backups on the first sat/sun night
># of each month.
>deleteprune cmd="cyr_expire -E 4 -D 69" at=0430
>expungeprune cmd="cyr_expire -E 4 -X 69" at=0445
>
># this is only necessary if caching TLS sessions
>tlsprune cmd="tls_prune" at=0400
>
># Uncomment the next entry, if you want to automatically remove
># old messages of EVERY user.
># This example calls ipurge every 60 minutes and ipurge will delete
># ALL messages older then 120 days.
># enter 'man 8 ipurge' for more details
>#cleanup cmd="ipurge -d 120 -f" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain1.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain2.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain3.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain4.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain5.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain6.com" period=60
>
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain1.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain2.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain3.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain4.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain5.com" period=60
>cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain6.com" period=60
>
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain1.com" period=60
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain2.com" period=60
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain3.com" period=60
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain4.com" period=60
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain5.com" period=60
>cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain6.com" period=60
>
># Create search indexes regularly
>squatter cmd="squatter -s -i" at=0530
>
># running sa-learn
>sa-learn cmd="/usr/local/bin/cyrus-salearn.pl" period=60
>sa-update cmd="/usr/bin/sa-update -v" at=0000
>
>}
>
>MAILSERVER:~ # cat /etc/imapd.domain1.com.conf
>configdirectory: /var/lib/imap
>partition-default: /var/spool/imap
>sievedir: /var/lib/sieve
>annotation_definitions: /etc/imapd.annotations.conf
># admins: cyrus at domain1.net
>allowanonymouslogin: no
>autocreatequota: 10000
>reject8bit: no
>quotawarn: 90
>timeout: 30
>poptimeout: 10
>dracinterval: 0
>drachost: localhost
>sasl_pwcheck_method: saslauthd
>lmtp_overquota_perm_failure: no
>#lmtp_catchall_mailbox: admin
>lmtp_downcase_rcpt: yes
>lmtp_fuzzy_mailbox_match: yes
>expunge_mode: delayed
>deletedprefix: DELETED
>delete_mode: delayed
>
># added by Michael Hieb Jun 22 2014
>allowplaintext: yes
>unixhierarchysep: yes
>allowplainwithouttls: no
>altnamespace: no
>virtdomains: userid
>servername: imap.domain1.net
>
>#
># if you want TLS, you have to generate certificates and keys
>#
>tls_cert_file: /etc/letsencrypt/live/imap.domain1.net/cert.pem
>tls_key_file: /etc/letsencrypt/live/imap.domain1.net/privkey.pem
>tls_ca_file: /etc/letsencrypt/live/imap.domain1.net/chain.pem
>tls_ca_path: /etc/ssl/certs
>tls_versions: tls1_0 tls1_1 tls1_2
>
># added by Michael Hieb 20-Jan-2017 for lmtp on port (not socket)
>lmtp_admins: lmtpuser
>MAILSERVER:~ #
>
>Note: before I discovered the problem with forking could be triggered
>by 
>switching between single threaded and multi-threaded cyrus server, I 
>thought problem could be related to resource constraints. This is why I
>
>set all processes with maxchild=-1 maxforkrate=100. I also set the 
>following in /etc/systemd/system/cyrus.service
>
>MAILSERVER:~ # cat /etc/systemd/system/cyrus.service
>[deleted...]
>LimitRTPRIO=50000
>LimitNOFILE=50000
>LimitNPROC=50000
>MAILSERVER:~ #
>
>None of these resource settings made any difference and the problem
>goes 
>away as soon as cyrus is single threaded - so I do not believe it is a 
>resource constraint (at least one I understand at this point).
>
>Any help would be much appreciated.
>
>
>
>----
>Cyrus Home Page: http://www.cyrusimap.org/
>List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
>To Unsubscribe:
>https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.andrew.cmu.edu/pipermail/info-cyrus/attachments/20170519/7d82b2f1/attachment-0001.html>