stuck lmtpd processes

[Andrew Morgan]

I logged onto my cyrus mail server today and found that I have about 500
lmtpd process that seem to be stuck trying to deliver mail to a single
user's inbox.

I am accepting mail directly to cyrus' lmtpd from a separate machine
running postfix, which is our campus mail relay.  The following is the
message I see in the postfix logs for all delivery attempts after 9:07am
yesterday:

Sep 22 09:16:56 smtp2 postfix/lmtp[30332]: 4F275170085: to=<krolickp at onid.orst.edu>, relay=mail1.onid.oregonstate.edu[128.193.4.128], delay=600, status=deferred (conversation with mail1.onid.oregonstate.edu[128.193.4.128] timed out while sending end of data -- message may be sent more than once)

All of the lmtpd processes seem to be stuck trying to obtain a lock:

[root at mail1 config]# strace -p 27332
fcntl64(13, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}

And here is the lsof output from one of these stuck lmtpd processes:

COMMAND   PID  USER   FD   TYPE     DEVICE     SIZE     NODE NAME
lmtpd   27332 cyrus  cwd    DIR        8,2     4096        2 /
lmtpd   27332 cyrus  rtd    DIR        8,2     4096        2 /
lmtpd   27332 cyrus  txt    REG        8,2  1562302  3014706 /usr/local/cyrus/bin/lmtpd
lmtpd   27332 cyrus  mem    REG        8,2    90210   180307 /lib/ld-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2   265900    32792 /usr/local/lib/libsasl2.so.2.0.15
lmtpd   27332 cyrus  mem    REG       8,17     8192 11665411 /private/cyrus/config/db/__db.001
lmtpd   27332 cyrus  mem    REG        8,2   182084  2064435 /usr/lib/libssl.so.0.9.6
lmtpd   27332 cyrus  mem    REG        8,2   771908  2064434 /usr/lib/libcrypto.so.0.9.6
lmtpd   27332 cyrus  mem    REG        8,2    56480   180323 /lib/libresolv-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2   684092  2064403 /usr/lib/libdb3.so.3.0.2
lmtpd   27332 cyrus  mem    REG        8,2    24328   180305 /lib/libwrap.so.0.7.6
lmtpd   27332 cyrus  mem    REG        8,2    69472   180315 /lib/libnsl-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2  1153784   180310 /lib/libc-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2     8008   180313 /lib/libdl-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2    98114  3031068 /usr/local/lib/sasl2/libsasldb.so.2.0.15
lmtpd   27332 cyrus  mem    REG        8,2    75762  3031072 /usr/local/lib/sasl2/libplain.so.2.0.15
lmtpd   27332 cyrus  mem    REG        8,2    19136   180311 /lib/libcrypt-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2    74972  3031076 /usr/local/lib/sasl2/libanonymous.so.2.0.15
lmtpd   27332 cyrus  mem    REG       8,17   270336 11665412 /private/cyrus/config/db/__db.002
lmtpd   27332 cyrus  mem    REG       8,17    98304 11665413 /private/cyrus/config/db/__db.003
lmtpd   27332 cyrus  mem    REG       8,17 16064512 11665414 /private/cyrus/config/db/__db.004
lmtpd   27332 cyrus  mem    REG       8,17    24576 11665415 /private/cyrus/config/db/__db.005
lmtpd   27332 cyrus  mem    REG       8,17 11562604  9797758 /private/cyrus/config/mailboxes.db
lmtpd   27332 cyrus  mem    REG       8,17      167 42107658 /private/cyrus/mail/k/user/krolickp/cyrus.header
lmtpd   27332 cyrus  mem    REG        8,2    32668   180318 /lib/libnss_files-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2    12176   180317 /lib/libnss_dns-2.2.5.so
lmtpd   27332 cyrus  mem    REG        8,2    40152   180316 /lib/libnss_compat-2.2.5.so
lmtpd   27332 cyrus    0u  IPv4   55681432               TCP mail1.onid.oregonstate.edu:cfinger->smtp2.oregonstate.edu:39183 (CLOSE_WAIT)
lmtpd   27332 cyrus    1u  IPv4   55681432               TCP mail1.onid.oregonstate.edu:cfinger->smtp2.oregonstate.edu:39183 (CLOSE_WAIT)
lmtpd   27332 cyrus    2u  IPv4   55681432               TCP mail1.onid.oregonstate.edu:cfinger->smtp2.oregonstate.edu:39183 (CLOSE_WAIT)
lmtpd   27332 cyrus    3w  FIFO        0,5               978 pipe
lmtpd   27332 cyrus    4u  IPv4        977               TCP *:cfinger (LISTEN)
lmtpd   27332 cyrus    5u   REG       8,17 10484911 11665942 /private/cyrus/config/db/log.0000000022 (deleted)
lmtpd   27332 cyrus    6r   REG       8,17 10484911 11665942 /private/cyrus/config/db/log.0000000022 (deleted)
lmtpd   27332 cyrus    7u   REG       8,17  7716864  9797635 /private/cyrus/config/deliver.db
lmtpd   27332 cyrus    8u   REG       8,17 11562604  9797758 /private/cyrus/config/mailboxes.db
lmtpd   27332 cyrus    9u   REG       8,17        0 11698179 /private/cyrus/config/socket/lmtp.lock
lmtpd   27332 cyrus   10u   REG       8,17     4011  7017174 /private/cyrus/mail/stage./27332-1064247785
lmtpd   27332 cyrus   11u  unix 0xce23fb00          55681436 socket
lmtpd   27332 cyrus   12u   REG       8,17   589824  9797636 /private/cyrus/config/tls_sessions.db
lmtpd   27332 cyrus   13u   REG       8,17      167 42107658 /private/cyrus/mail/k/user/krolickp/cyrus.header

I'm willing to let this problem stick around for a while if there is
something I can do to help debug this.  It seems to be only affecting one
user's mail delivery.  If anyone has any suggestions, please email me or
join me in #cyrus on irc.freenode.net.

I'd prefer not to restart all of cyrus because I have several hundred
users connected right now, and this is the day that all the students are
returning to campus.  Is there a way I can kill the original lmtpd process
that got stuck to free things up?

	Andy