On 3/31/2016 3:30 PM, jaso...@mail-central.com wrote: > I'd like to understand postscreen's cache behavior a bit better than I do. > > Looking at my logs for one example > > Mar 29 18:25:28 mail01 postfix/postscreen[24234]: CONNECT from > [79.13.92.233]:64564 to [192.0.2.24]:25 > Mar 29 18:25:28 mail01 postfix/dnsblog[24238]: addr 79.13.92.233 listed > by domain zen.spamhaus.org as 127.0.0.10 > Mar 29 18:25:28 mail01 postfix/dnsblog[24240]: addr 79.13.92.233 listed > by domain dnsbl.sorbs.net as 127.0.0.10 > Mar 29 18:25:34 mail01 postfix/postscreen[24234]: DNSBL rank 10 for > [79.13.92.233]:64564 > Mar 29 18:25:34 mail01 postfix/postscreen[24234]: NOQUEUE: reject: RCPT > from [79.13.92.233]:64564: 550 5.7.1 Service unavailable; client > [79.13.92.233] blocked using zen.spamhaus.org; from=<tend...@onet.eu>, > to=<myaddr...@example.com>, proto=ESMTP, helo=<[79.13.92.233]> > Mar 29 18:25:35 mail01 postfix/postscreen[24234]: HANGUP after 0.79 > from [79.13.92.233]:64564 in tests after SMTP handshake > Mar 29 18:25:35 mail01 postfix/postscreen[24234]: DISCONNECT > [79.13.92.233]:64564 > Mar 29 18:26:02 mail01 postfix/postscreen[24234]: CONNECT from > [79.13.92.233]:57377 to [192.0.2.24]:25 > Mar 29 18:26:02 mail01 postfix/dnsblog[24237]: addr 79.13.92.233 listed > by domain zen.spamhaus.org as 127.0.0.10 > Mar 29 18:26:02 mail01 postfix/dnsblog[24237]: addr 79.13.92.233 listed > by domain dnsbl.sorbs.net as 127.0.0.10 > Mar 29 18:26:08 mail01 postfix/postscreen[24234]: DNSBL rank 10 for > [79.13.92.233]:57377 > Mar 29 18:26:08 mail01 postfix/postscreen[24234]: NOQUEUE: reject: RCPT > from [79.13.92.233]:57377: 550 5.7.1 Service unavailable; client > [79.13.92.233] blocked using zen.spamhaus.org; from=<sweatedt...@onet.eu>, > to=<myaddr...@example.com>, proto=ESMTP, helo=<[79.13.92.233]> > Mar 29 18:26:08 mail01 postfix/postscreen[24234]: HANGUP after 0.75 > from [79.13.92.233]:57377 in tests after SMTP handshake > Mar 29 18:26:08 mail01 postfix/postscreen[24234]: DISCONNECT > [79.13.92.233]:57377 > > That looks to me like the dnsblog checks, to zen.spamhaus.org and > dnsbl.sorbs.net, are run twice.
The dnsblog results are cached both locally in the dnsblog service, and on your local DNS server ** subject to the TTL set by the DNSBL operator **. > > My understanding was that postscreen, once it catches a bad actor, it caches > the result so subsequent attempts get a response from the cache. IIRC postscreen caches PASS results only. > > Is what I'm seeing here, the 2nd set of dnsblog results, actually from the > postscreen cache? Or am I actually seeing the check run (unnecessarily) > twice? The dnsblog results are from the cache if they exist. > > If it's the former, how can I better detect & indicate in logs that it's a > cached result? > > If it's the second, what can I do to prevent the 2nd unncessary check? Why do you care? If the prior results are still in the cache, they're used. If not, another lookup is made. Not much you can do about it either way, other than blacklist repeat offenders in the postscreen_access_list. Postfix 3.1 introduced postscreen_dnsbl_min_ttl (and postscreen_dnsbl_max_ttl) to reduce repeated DNS lookups in a short period of time for DNSBL sites that use a very short timeout. -- Noel Jones
