[Mimedefang] sudden "Too many open files" errors

[Juergen Georgi]

Hello,

yesterday about noon, MIMEDefang started to complain about 
"Too many open files". The log shows error messages like:

Apr 18 09:26:14 smtp5.BelWue.DE mimedefang[24437]: [ID 384225 local0.warning] l3I7Q3Kf006561: Could not open /var/run/MIMEDefang/mdefang-l3I7Q3Kf006561/HEADERS: Too many open files
Apr 18 09:26:14 smtp5.BelWue.DE mimedefang[24437]: [ID 384225 local0.warning] l3I7Q3Kf006561: Could not open /var/run/MIMEDefang/mdefang-l3I7Q3Kf006561/COMMANDS: Too many open files
Apr 18 09:26:14 smtp5.BelWue.DE mimedefang[24437]: [ID 934268 local0.warning] opendir(/var/run/MIMEDefang/mdefang-l3I7Q3Kf006561) failed: Too many open files
Apr 18 09:26:14 smtp5.BelWue.DE mimedefang[24437]: [ID 828695 local0.error] l3I7Q3Kf006561: failed to clean up /var/run/MIMEDefang/mdefang-l3I7Q3Kf006561: Too many open files

In /var/run/MIMEDefang I find are tons (> 10000) of left-over 
mdefang-<qid> directories. lsof reports that mimdefang[24437] 
has nearly 1000 files open (fd limit is 1024).

I looked for those open files: 385 open connections on mimedefang.sock, 
and 606 files in mdefang-<qid> directories. Here an example:

# date
Wed Apr 18 09:56:53 MEST 2007

# ls -l /var/run/MIMEDefang/mdefang-l3I7IKjT002406/*
-rw-r-----   1 defang   defang       472 Apr 18 09:18 /var/run/MIMEDefang/mdefang-l3I7IKjT002406/COMMANDS
-rw-r-----   1 defang   defang         0 Apr 18 09:18 /var/run/MIMEDefang/mdefang-l3I7IKjT002406/HEADERS

# lsof /var/run/MIMEDefang/mdefang-l3I7IKjT002406/COMMANDS
COMMAND     PID   USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
mimedefan 24437 defang 1015u  VREG    0,1      472 83849661 /var/run/MIMEDefang/mdefang-l3I7IKjT002406/COMMANDS

# lsof /var/run/MIMEDefang/mdefang-l3I7IKjT002406/HEADERS
COMMAND     PID   USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
mimedefan 24437 defang 1003u  VREG    0,1        0 84549498 /var/run/MIMEDefang/mdefang-l3I7IKjT002406/HEADERS

# cat /var/run/MIMEDefang/mdefang-l3I7IKjT002406/COMMANDS
S<Maks at antra-ag.de>
sSIZE=66285
=_ 62.43.196.178.static.user.ono.com%20[62.43.196.178]
=daemon_name MTA-v4
=i l3I7IKjT002406
=if_addr 129.143.2.36
=if_name smtp5b.BelWue.DE
=j smtp5.BelWue.DE
=mail_addr Maks at antra-ag.de
=mail_host antra-ag.de.
=mail_mailer esmtp
Ql3I7IKjT002406
H62.43.196.178.static.user.ono.com
I62.43.196.178
E62-43-196-178.user.ono.com
R<mkins at stud.fh-heilbronn.de> esmtp [dns1.rz.hs-heilbronn.de]:[dns2.rz.hs-heilbronn.de] mkins at stud.fh-heilbronn.de

So why is mimedefang keeping these files open for more than 
half an hour? The strange thing is: I see no trace of queue 
id l3I7IKjT002406 in sendmail's or md's log. But I see the 
client IP 62.43.196.178 in sendmail log file (and in md's log
- see above), but with a different queue id:

Apr 18 09:26:14 smtp5.BelWue.DE sm-mta[6561]: [ID 801593 mail.info] l3I7Q3Kf006561: Milter: from=<Kowsarituow at antra-ag.de>, reject=451 4.3.2 Please try again later
Apr 18 09:26:14 smtp5.BelWue.DE sm-mta[6561]: [ID 801593 mail.info] l3I7Q3Kf006561: from=<Kowsarituow at antra-ag.de>, size=65671, class=0, nrcpts=0, proto=ESMTP, daemon=MTA-v4, relay=62.43.196.178.static.user.ono.com [62.43.196.178]

I observed this problem once two weeks ago. I mitigated it by 
stopping mimedefang and deleting/recreating /var/run/MIMEDefang 
a couple of times. The trouble eventually disappeared the next 
day. Now it is back again. I suspect that some malformed spam 
message is causing the problem. We run 3 MIMEDefang installations 
(mimedefang-2.62 + spamassassin-3.1.8 + clamav + sophie) on 
Solaris-8. They performed very reliable in the past, even under 
much higher load.

Any idea what is going wrong here, and what can be done to cure 
this problem?

Thanks,

-Juergen