Sahil Tandon:
> May 5 15:24:07 mx1 postfix/postscreen[38500]: CONNECT from
> [88.23.204.109]:40294 to [69.147.83.52]:25
> May 5 15:24:07 mx1 postfix/dnsblog[45237]: addr 88.23.204.109 listed by
> domain bl.spameatingmonkey.net as 127.0.0.3
> May 5 15:24:07 mx1 postfix/dnsblog[45234]: addr 88.23.204.109 listed by
> domain zen.spamhaus.org as 127.0.0.11
> May 5 15:24:07 mx1 postfix/dnsblog[45234]: addr 88.23.204.109 listed by
> domain zen.spamhaus.org as 127.0.0.4
> May 5 15:24:09 mx1 postfix/postscreen[38500]: DNSBL rank 5 for
> [88.23.204.109]:40294
> May 5 15:24:09 mx1 postfix/postscreen[38500]: HANGUP after 0.24 from
> [88.23.204.109]:40294 in tests after SMTP handshake
> May 5 15:24:09 mx1 postfix/postscreen[38500]: DISCONNECT
> [88.23.204.109]:40294
>
> In this second instance, is it correct to infer that Postfix was under
> stress given the 2s (rather than 6s) that elapses between the last
> dnsblog(8) entry and when the DNSBL rank is logged by postscreen(8)?
No. What your see is this: there are no more before-220 tests when
the DNBLS lookups complete, therefore postscreen makes its decision
immediately.
Either you have pregreet tests turned off, or this this client has
already passed the pregreet test recently, and that result was
cached in the temporary whitelist database.
By the way, what is going on with your DNS? Why do both DNSBL replies
arrive (almost) simultaneously after two seconds?
> May 5 15:25:08 mx1 postfix/postscreen[38500]: CONNECT from
> [88.23.204.109]:41253 to [69.147.83.52]:25
> May 5 15:25:10 mx1 postfix/dnsblog[45304]: addr 88.23.204.109 listed by
> domain zen.spamhaus.org as 127.0.0.4
> May 5 15:25:10 mx1 postfix/dnsblog[45304]: addr 88.23.204.109 listed by
> domain zen.spamhaus.org as 127.0.0.11
> May 5 15:25:10 mx1 postfix/dnsblog[45300]: addr 88.23.204.109 listed by
> domain bl.spameatingmonkey.net as 127.0.0.3
> May 5 15:25:10 mx1 postfix/postscreen[38500]: NOQUEUE: reject: RCPT from
> [88.23.204.109]:41253: 450 4.3.2 Service currently unavailable;
> from=<unlacesj...@clickz.com>, to=<freebsd-...@freebsd.org>,
> proto=ESMTP, helo=<109.Red-88-23-204.staticIP.rima-tde.net>
> May 5 15:25:11 mx1 postfix/postscreen[38500]: HANGUP after 1.1 from
> [88.23.204.109]:41253 in tests after SMTP handshake
> May 5 15:25:11 mx1 postfix/postscreen[38500]: PASS NEW [88.23.204.109]:41253
> May 5 15:25:11 mx1 postfix/postscreen[38500]: DISCONNECT
> [88.23.204.109]:41253
postscreen sends out DNSBL lookup requests because the client is
not yet whitelisted for this test.
Notice that again, both DNSBL replies arrive two seconds later.
Apparently this time the DNSBL score did not reach your '5' threshold,
so the client is not blocked. Perhaps some bit got flipped as the
dnsblog reported its results to the postscreen daemon; postscreen
'-v' logging will show how it maintains DNSBL scores.
Next, postscreen does what it is supposed to do when the DNSBL tests
succeeds: it saves the result to the temporary whitelist database
and logs PASS NEW, because all tests are now completed.
If this discrepancy is reproducible let me know. Otherwise I
will not lose sleep over this.
Wietse
