Cyrus imapd stalling with multiple instances

Tuomas Toropainen tuomas.toropainen at lanwan.fi
Tue Jan 9 10:08:14 EST 2007 

Hello everyone

I'm trying to accomplish 2 things:
1) prevent plain logins without ssl/tls over network
2) prevent cyrus admin user(s) from logging in over network
(users are authenticated from ldap and admin(s) from local sasldb)

I have figured out one way to do this. Please tell me if I'm trying to
do it incorrectly or in otherwise not-so-wise way. I have tried to run 2
separate cyrus imapd instances: one for users to connect over network
(which listens on imap.lanwan.fi service ip address) and another for
administrative use which only listens on localhost. Both instances are
defined in /etc/cyrus.conf.

The platform is debian testing (etch RC1), with cyrus installed from
debian provided package.

The problem is, that with this kind of configuration, cyrus occasionally
stops responding to one (or both) addresses. Cyrus is running, and tcp
connection is fine, but imapd doesn't respond with usual imap banner or
to any commands at all. After waiting for some while (a minute or five),
imapd (usually) responds again. Maybe an example is in place to point
out what I mean.

Normally when everything works fine, this is what I see:

# telnet imap.lanwan.fi imap
Trying 213.255.190.58...
Connected to imap.lanwan.fi.
Escape character is '^]'.
* OK imap.lanwan.fi Cyrus IMAP4 v2.2.13-Debian-2.2.13-10 server ready

But when problems occur, thing look this way (I have deliberately
disconnected telnet after waiting a while):

# telnet imap.lanwan.fi imap
Trying 213.255.190.58...
Connected to imap.lanwan.fi.
Escape character is '^]'.
^]
telnet> c
Connection closed.

I have searched mailing lists and google, but not found anything like
this. I tried to debug cyrus and here are the results. The debug log
(CYRUS_VERBOSE=1) doesn't reveal anything special:

(here the tcp connection is established)

Jan  9 15:27:37 delta cyrus/master[5616]: set maximum file descriptors
to 256/256
Jan  9 15:27:37 delta cyrus/master[5616]: about to exec
/usr/lib/cyrus/bin/imapd
Jan  9 15:27:37 delta cyrus/imap[5616]: running external debugger:
/usr/bin/strace -tt -o /tmp/strace.cyrus.imapd.5616 -p 5616 <&- 2>&1 &
Jan  9 15:27:37 delta cyrus/imap[5616]: debugger returned exit status: 0
Jan  9 15:27:37 delta cyrus/imap[5616]: executed

(here cyrus responds with imap banner)

Jan  9 15:28:35 delta cyrus/master[5578]: process 5593 exited, status 0
Jan  9 15:28:35 delta cyrus/master[5578]: service imap now has 0 ready
workers
Jan  9 15:28:35 delta cyrus/imap[5616]: telling master 2
Jan  9 15:28:35 delta cyrus/master[5578]: service imap pid 5616 in READY
state: now unavailable and in BUSY state
Jan  9 15:28:35 delta cyrus/master[5578]: service imap now has 0 ready
workers
Jan  9 15:28:35 delta cyrus/imap[5616]: accepted connection
Jan  9 15:28:35 delta cyrus/imap[5616]: telling master 3
Jan  9 15:28:35 delta cyrus/master[5578]: service imap pid 5616 in BUSY
state: now serving connection
Jan  9 15:28:35 delta cyrus/master[5578]: service imap now has 0 ready
workers

Here is also an excerpt from imapd strace:

15:27:37.130492 stat64("/usr/lib/cyrus/bin/imapd",
{st_mode=S_IFREG|0755, st_size=984752, ...}) = 0
15:27:37.130579 open("/var/lib/cyrus/socket/imap-0.lock",
O_RDWR|O_CREAT, 0600)
= 12
15:27:37.130651 rt_sigaction(SIGALRM, {0x8088300, [], SA_ONESHOT}, NULL,
8) = 0
15:27:37.130698 rt_sigaction(SIGHUP, {0x8088300, [],
SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
15:27:37.130746 rt_sigaction(SIGINT, {0x8088300, [],
SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
15:27:37.130792 rt_sigaction(SIGQUIT, {0x8088300, [],
SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
15:27:37.130839 fcntl64(12, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET,
start=0, len=0}

(previous line is last after tcp connection is established, and below is
the same line and some that follow after cyrus responds with imap
banner, so it looks like that imapd process stalls in fcntl64() syscall?)

15:27:37.130839 fcntl64(12, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET,
start=0, len=0}) = 0
15:28:35.286038 stat64("/usr/lib/cyrus/bin/imapd",
{st_mode=S_IFREG|0755, st_size=984752, ...}) = 0
15:28:35.286153 accept(4, 0, NULL)      = 13
15:28:35.286199 fcntl64(12, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET,
start=0, len=0}) = 0
15:28:35.286247 alarm(0)                = 0


Here are complete cyrus configuration files (with debugging turned off
and comments stripped):

/etc/cyrus.conf

START {
         recover         cmd="/usr/sbin/ctl_cyrusdb -r"

         delprune        cmd="/usr/sbin/cyr_expire -E 3"
         tlsprune        cmd="/usr/sbin/tls_prune"
}
SERVICES {
         imap            cmd="imapd -U 30" listen="213.255.190.58:imap"
prefork=0 maxchild=100
         imaps           cmd="imapd -s -U 30"
listen="213.255.190.58:imaps" prefork=0 maxchild=100
         imap            cmd="imapd -U 30 -C /etc/imapd.conf.localhost"
listen="127.0.0.1:imap" prefork=0 maxchild=100
         lmtpunix        cmd="lmtpd"
listen="/var/spool/postfix/extern/cyrus/lmtp" prefork=0 maxchild=20
         sieve           cmd="timsieved" listen="localhost:sieve"
prefork=0 maxchild=100
         notify          cmd="notifyd"
listen="/var/run/cyrus/socket/notify" proto="udp" prefork=1
}
EVENTS {
         checkpoint      cmd="/usr/sbin/ctl_cyrusdb -c" period=30
         delprune        cmd="/usr/sbin/cyr_expire -E 3" at=0401
         tlsprune        cmd="/usr/sbin/tls_prune" at=0401

}


/etc/imapd.conf

configdirectory: /var/lib/cyrus
defaultpartition: default
partition-default: /var/spool/cyrus/mail
partition-news: /var/spool/cyrus/news
newsspool: /var/spool/news
servername: imap.lanwan.fi
altnamespace: no
unixhierarchysep: no
lmtp_downcase_rcpt: yes
admins: cyrus
allowanonymouslogin: no
popminpoll: 1
autocreatequota: 0
umask: 077
sieveusehomedir: false
sievedir: /var/spool/sieve
hashimapspool: true
allowplaintext: no
sasl_mech_list: PLAIN
sasl_pwcheck_method: saslauthd auxprop
sasl_auxprop_plugin: sasldb
sasl_auto_transition: no
tls_cert_file: /etc/ssl/certs/ssl-cert-snakeoil.pem
tls_key_file: /etc/ssl/private/ssl-cert-snakeoil.key
tls_ca_path: /etc/ssl/certs
tls_session_timeout: 1440
tls_cipher_list: TLSv1+HIGH:!aNULL:@STRENGTH
lmtpsocket: /var/spool/postfix/extern/cyrus/lmtp
idlemethod: poll
idlesocket: /var/run/cyrus/socket/idle
notifysocket: /var/run/cyrus/socket/notify
syslog_prefix: cyrus



/etc/imapd.conf.localhost

configdirectory: /var/lib/cyrus
defaultpartition: default
partition-default: /var/spool/cyrus/mail
partition-news: /var/spool/cyrus/news
newsspool: /var/spool/news
servername: imap.lanwan.fi
altnamespace: no
unixhierarchysep: no
lmtp_downcase_rcpt: yes
admins: cyrus
allowanonymouslogin: no
popminpoll: 1
autocreatequota: 0
umask: 077
sieveusehomedir: false
sievedir: /var/spool/sieve
hashimapspool: true
allowplaintext: yes
sasl_mech_list: PLAIN
sasl_pwcheck_method: auxprop
sasl_auxprop_plugin: sasldb
sasl_auto_transition: no
tls_ca_path: /etc/ssl/certs
tls_session_timeout: 1440
tls_cipher_list: TLSv1+HIGH:!aNULL:@STRENGTH
lmtpsocket: /var/spool/postfix/extern/cyrus/lmtp
idlemethod: poll
idlesocket: /var/run/cyrus/socket/idle
notifysocket: /var/run/cyrus/socket/notify
syslog_prefix: cyrus


The complete imapd strace can be found from
http://www.lanwan.fi/~ttor/strace.cyrus.imapd.5616
There is also cyrmaster strace at
http://www.lanwan.fi/~ttor/strace.cyrus.master.5658
In cyrmaster trace, line 404 is the first line after imap banner. I
don't know if these reveal anything, but I think too much information is
better than too little :)

Thank you in advance :)

More information about the Info-cyrus mailing list