Timeout before data read
2014-02-28 by Jim Klimov
Hello, Every once in a while I inspect the SPAM which makes it into my inbox to see why it passed. Sometimes I see no headers added by milter-greylist which is of course curious. In one case I tracked it to this snippet in the sendmail/milter debug-log on the relay: Feb 28 13:46:51 relay-mta sendmail[11077]: [ID 801593 mail.info] s1QEJTG9025599: to=<gooduser@...>, delay=1+19:27:20, xdelay=00:00:00, mailer=esmtp, pri=709686123, relay=good.remote.domain.ru., dsn=4.0.0, stat=Deferred: Connection timed out with good.remote.domain.ru. Feb 28 13:46:53 relay-mta sendmail[9494]: [ID 801593 mail.error] s1S9fS5u009494: Milter (greylist): timeout before data read, where=rcpt Feb 28 13:46:53 relay-mta sendmail[9494]: [ID 801593 mail.info] s1S9fS5u009494: Milter (greylist): to error state Feb 28 13:46:55 relay-mta sendmail[9494]: [ID 801593 mail.info] s1S9fS5u009494: from=<office@...>, size=5510, class=0, nrcpts=1, msgid=<201402281741071561977354520@...>, proto=SMTP, daemon=relay-mta.cos.ru, relay=[199.36.72.246] So, in this case I see lots of un-deliveries to the (obfuscated) "@..." whose relay is apparently under maintenance. Maybe this is related, maybe not, to the milter-greylist timeout reported further on. The daemon is up and running since about midnight, and it has been properly processing messages more recently than that log entry, so it was some intermittent hiccup. And due to this hiccup the relay happened to be unprotected at all, and accepted the spam message (a few minutes later it did process another delivery attempt and put it off into the 8-hour greylist): Feb 28 13:55:00 relay-mta milter-greylist: [ID 751384 mail.info] s1S9fS5u009494: addr [199.36.72.246][199.36.72.246] from <office@...> to <info@...> delayed for 08:00:00 (ACL 1825) Feb 28 13:55:00 relay-mta milter-greylist: [ID 765981 mail.info] (199.36.72.246 SP:+0) SPF unknown: undefined result received while evaluating SPF for sender domain 'buyouproduct.pw', accept any relay Feb 28 13:55:00 relay-mta milter-greylist: [ID 902047 mail.info] MGL-TEMPFAIL-DNS-480: IP:'199.36.72.246' DOMAIN:'[199.36.72.246]' HELO:'VPS-30E0C4FBE64' FROM:'office@...' RCPT:'info@...': Source looks like a probable spam-source (scored 20 in DNS, 5 in P0F) (max delay 480m) Feb 28 13:55:00 relay-mtc milter-greylist: [ID 556459 mail.debug] created: 199.36.72.246 from <office@...> to <info@...> delayed for 08:00:00 So... are there any ideas why could milter-greylist be considered offline by sendmail for a short while, and what can be done to prevent this? It is running on the same host as the relay, version 4.5.7. Apparently, things like these happen on all of our relays once in a while with no noticed correlation. Maybe something to do with load and thus latency (CPU or RAM overbooking)? I wonder if it would make sense to require that sendmail uses the milter or tempfails the message submission attempt... and if it is possible to not-use the milter for local (LAN) addresses at all :) Ideas/doclinks on this are also welcome, thanks in advance ;) //Jim