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

Fri May 19 05:48:36 EDT 2017

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.