Milter-greylist

(NB: j'\ufffdcris en anglais car je pensais poster le message sur la liste
milter-greylist, mais vu la sp\ufffdcificit\ufffd du pb je voudrais avoir ton avis
avant)


I just noticed we're getting many "Milter (greylist): timeout before
data read" in our maillog. This used to be sporadic (every hour or so),
but catched my attention this morning because yesterday's report
outlined very unusual SPAM rates.

In the typical case, the milter-greylist ACL was already matched and
logged, which should have resulted in 5xx blocked ou 4xx delayed mail
(depending ACL), but the mail is still accepted by sendmail due (?) to
the timeout (see attached log fragment).

We use only RCPT-stage ACLs and currently have 63 of them.

The milter-greylist version is 4.0rc1, but quick log digging seems to
indicate that the same problem was present when we were using 2.02 and
had much less ACLs (only whitelist ones).

The system is a 32-bit Debian Linux with an AMD64 2.6.16 kernel. glibc
is 2.3.2.

Milter-greylist is configured with:
./configure --prefix=/usr/local --bindir=/usr/local/sbin
--sysconfdir=/etc --localstatedir=/var/lib --enable-dnsrbl
--with-libspf2_10=/usr/lib --with-conffile=/etc/mail/greylist
.conf --with-dumpfile=/var/lib/milter-greylist/greylist.db
--with-libbind=/usr/lib  --with-libcurl=/usr/lib

Since the ACL match is already logged, I suppose the timeout is not
caused by the ACL itself (long-responding DNSRBL, URLCHECK or SPF
query), but who knows.

I consider this being a quite serious problem, since it overcomes the
filtering rules.

Any idea ?


---- typical log fragment attached :

Oct 22 08:48:20 asterix sm-mta[7719]: l9M6m9bd007719: Milter (greylist):
timeout before data read
Oct 22 08:48:20 asterix sm-mta[7719]: l9M6m9bd007719: Milter (greylist):
to error state
Oct 22 08:48:21 asterix sm-mta[7719]: l9M6m9bd007719: from=<xxx@xxx>,
size=1285, class=0, nrcpts=1, msgid=46802457801346791, proto=ESMTP,
daemon=MTA-v6, relay=xxx [a.a.a.a]
Oct 22 08:48:35 asterix sendmail[7874]: l9M6m9bd007719: to=yyy,
delay=00:00:15, xdelay=00:00:00, mailer=local, pri=31285, dsn=2.0.0,
stat=Sent
Oct 22 08:48:38 asterix milter-greylist: l9M6m9bd007719: addr
xxx[a.a.a.a] from <xxx@xxx> to <yyy@...> delayed for
00:05:00 (ACL 432)


-- 
Ce message a ete verifie par MailScanner
pour des virus ou des polluriels et rien de
suspect n'a ete trouve.

Benoit Branciard a \ufffdcrit :
> 
> I just noticed we're getting many "Milter (greylist): timeout before
> data read" in our maillog. This used to be sporadic (every hour or so),
> but catched my attention this morning because yesterday's report
> outlined very unusual SPAM rates.
> 

This was caused by some DNSRBL checks taking up to 30 seconds.

I pushed up the R timeout value in sendmail.cf (ex: "Xgreylist, 
S=local:/path/to/socket, T=R:1m") and disabled the faulty DNSRBL in 
greylist.conf, and all seems to be fine now.

Sendmail's default R value is quite low (5 seconds), one may have to 
pump it up to something more comfortable (30s or more) for each 
milter-greylist setup involving DNS-intensive tasks such as SPF, DNSWL 
our urlcheck; Maybe a word about this in the installation doc may be 
helpful ?

By the way, when in "verbose" mode, milter-greylist 4.0rc1 logs response 
times for SPF checks, but not DNSRBL and urlcheck queries. The two 
attached patches corrects this issue. Very handy to diagnose those 
timeout issues...




-- 
Ce message a ete verifie par MailScanner
pour des virus ou des polluriels et rien de
suspect n'a ete trouve.