persistent postscreen_cache

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

persistent postscreen_cache

biggsy
Hello all,

I'm running postfix postfix-3.3.1 on FreeBSD 11.1-RELEASE.

For quite a long time I've used a persistent postscreen_cache file:

postscreen_cache_map = btree:/var/db/postfix/postscreen_cache
postscreen_cache_retention_time = 90d

The postscreen_cache.db file is there and seems to be updated.

A few times in the past I've noticed that, after rebooting the server,
IP addresses that are in the postscreen_cache.db are bounced with
a "Service currently unavailable".

I decided to check one of these today after a reboot and found that the dates
and times for the IP appear to be within the 90 day retention period:

Using postmap -s btree:/var/db/postfix/postscreen_cache:

203.38.21.10    1533826625;1533740285;1534656999;1534656999;1534656999

1533826625      2018-08-09 14:57:05
1533740285      2018-08-08 14:58:05
1534656999      2018-08-19 05:36:39
1534656999      2018-08-19 05:36:39
1534656999      2018-08-19 05:36:39

(Although I have no idea what these dates and times represent.)

Have I misunderstood the purpose and/or use of the persistent cache?

Thanks



 

Reply | Threaded
Open this post in threaded view
|

Re: persistent postscreen_cache

Wietse Venema
Phil Biggs:

> Hello all,
>
> I'm running postfix postfix-3.3.1 on FreeBSD 11.1-RELEASE.
>
> For quite a long time I've used a persistent postscreen_cache file:
>
> postscreen_cache_map = btree:/var/db/postfix/postscreen_cache
> postscreen_cache_retention_time = 90d
>
> The postscreen_cache.db file is there and seems to be updated.
>
> A few times in the past I've noticed that, after rebooting the server,
> IP addresses that are in the postscreen_cache.db are bounced with
> a "Service currently unavailable".

Postfix for privacy reasons does not divulge every detail in its
responses to SMTP clients. To find out more about the problem, look
in the logs, and report what it says there.

http://www.postfix.org/DEBUG_README.html#logging

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: persistent postscreen_cache

biggsy
Friday, October 19, 2018, 4:38:45 AM, Wietse wrote:

> Phil Biggs:
>> Hello all,
>>
>> I'm running postfix postfix-3.3.1 on FreeBSD 11.1-RELEASE.
>>
>> For quite a long time I've used a persistent postscreen_cache file:
>>
>> postscreen_cache_map = btree:/var/db/postfix/postscreen_cache
>> postscreen_cache_retention_time = 90d
>>
>> The postscreen_cache.db file is there and seems to be updated.
>>
>> A few times in the past I've noticed that, after rebooting the server,
>> IP addresses that are in the postscreen_cache.db are bounced with
>> a "Service currently unavailable".

> Postfix for privacy reasons does not divulge every detail in its
> responses to SMTP clients. To find out more about the problem, look
> in the logs, and report what it says there.

> http://www.postfix.org/DEBUG_README.html#logging

>         Wietse

Apologies for not including the relevant logs.  Is something more verbose required?

Previous interaction with 203.38.21.10

Aug  9 00:56:59 postfix/postscreen[31503]: CONNECT from [203.38.21.10]:60561 to [192.168.11.19]:25
Aug  9 00:57:05 postfix/postscreen[31503]: PASS OLD [203.38.21.10]:60561
Aug  9 00:57:05 postfix/smtpd[31505]: connect from nsstlmta10p.bpe.bigpond.com[203.38.21.10]
Aug  9 00:57:05 postfix/smtpd[31505]: DE9D63C9BE: client=nsstlmta10p.bpe.bigpond.com[203.38.21.10]
Aug  9 00:57:05 postfix/cleanup[31509]: DE9D63C9BE: message-id=<002301d42f28$0f62fd90$2e28f8b0$@optusnet.com.au>
Aug  9 00:57:06 postfix/qmgr[648]: DE9D63C9BE: from=<3rdPartyEmailAddr>, size=76103, nrcpt=1 (queue active)
Aug  9 00:57:06 postfix/smtpd[31505]: disconnect from nsstlmta10p.bpe.bigpond.com[203.38.21.10] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Aug  9 00:57:06 postfix/smtp[31510]: DE9D63C9BE: to=<myPrivateEmailAddr>, relay=192.168.11.2[192.168.11.2]:25, delay=0.57, delays=0.5/0.01/0.01/0.05, dsn=2.0.0, status=sent (250 Requested mail action okay, completed)
Aug  9 00:57:06 postfix/qmgr[648]: DE9D63C9BE: removed

There was a HANGUP in between:

Oct  5 16:23:56 postfix/postscreen[10718]: CONNECT from [203.38.21.10]:45738 to [192.168.11.19]:25
Oct  5 16:24:01 postfix/postscreen[10718]: HANGUP after 5.5 from [203.38.21.10]:45738 in tests before SMTP handshake
Oct  5 16:24:01 postfix/postscreen[10718]: DISCONNECT [203.38.21.10]:45738

Soon after reboot of postfix server

Oct 18 14:58:56 postfix/postscreen[1592]: CONNECT from [203.38.21.10]:35490 to [192.168.11.19]:25
Oct 18 14:59:02 postfix/postscreen[1592]: NOQUEUE: reject: RCPT from [203.38.21.10]:35490: 450 4.3.2 Service currently unavailable; from=<myISPemailAddr>, to=<myPrivateEmailAddr>, proto=ESMTP, helo=<nsstlmta10p.bpe.bigpond.com>
Oct 18 14:59:02 postfix/postscreen[1592]: PASS OLD [203.38.21.10]:35490
Oct 18 14:59:02 postfix/postscreen[1592]: DISCONNECT [203.38.21.10]:35490


Curiously, after a short time, cached addresses seem to be recognized again.  
For example, I see no rejection of mail from servers used by the postfix-users list.

Thanks

Reply | Threaded
Open this post in threaded view
|

Re: persistent postscreen_cache

Wietse Venema
Phil Biggs:
> Oct 18 14:58:56 postfix/postscreen[1592]: CONNECT from [203.38.21.10]:35490 to [192.168.11.19]:25
> Oct 18 14:59:02 postfix/postscreen[1592]: NOQUEUE: reject: RCPT from [203.38.21.10]:35490: 450 4.3.2 Service currently unavailable; from=<myISPemailAddr>, to=<myPrivateEmailAddr>, proto=ESMTP, helo=<nsstlmta10p.bpe.bigpond.com>
> Oct 18 14:59:02 postfix/postscreen[1592]: PASS OLD [203.38.21.10]:35490
> Oct 18 14:59:02 postfix/postscreen[1592]: DISCONNECT [203.38.21.10]:35490

The log shows a 6-second delay, meaning that the test for "pregreet"
was expired, or that no record was found in the postscreen
cache.

"Service currently unavailable" followed by "PASS" means that you
have one of:

    postscreen_bare_newline_enable = yes
    postscreen_non_smtp_command_enable = yes
    postscreen_pipelining_enable = yes

and some of the timestamps for these tests were too old, or that
no record was found in the postscreen cache. Until now, these tests
are not useful for blocking spambots; they always result in "Service
currently unavailable" if the test has expired which can be annoying.
I suggest that you turn these tests off.

After the "PASS" result, the timestamps for the expired tests will
be set to 'now', and those tests will be skipped until the timestamps
expire, or until the postscreen cache is deleted.

Is it possible that the reboot or 'postfix start' removes the
postscreen cache, as in: "rm -f $data_directory/*' or even 'rm -rf
$data_directory'?

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: persistent postscreen_cache

biggsy
Hello Wietse,

Friday, October 19, 2018, 11:15:49 AM, you wrote:

> Phil Biggs:
>> Oct 18 14:58:56 postfix/postscreen[1592]: CONNECT from [203.38.21.10]:35490 to [192.168.11.19]:25
>> Oct 18 14:59:02 postfix/postscreen[1592]: NOQUEUE: reject: RCPT from [203.38.21.10]:35490: 450 4.3.2 Service currently unavailable; from=<myISPemailAddr>, to=<myPrivateEmailAddr>, proto=ESMTP, helo=<nsstlmta10p.bpe.bigpond.com>
>> Oct 18 14:59:02 postfix/postscreen[1592]: PASS OLD [203.38.21.10]:35490
>> Oct 18 14:59:02 postfix/postscreen[1592]: DISCONNECT [203.38.21.10]:35490

> The log shows a 6-second delay, meaning that the test for "pregreet"
> was expired, or that no record was found in the postscreen
> cache.

> "Service currently unavailable" followed by "PASS" means that you
> have one of:

>     postscreen_bare_newline_enable = yes
>     postscreen_non_smtp_command_enable = yes
>     postscreen_pipelining_enable = yes

> and some of the timestamps for these tests were too old, or that
> no record was found in the postscreen cache. Until now, these tests
> are not useful for blocking spambots; they always result in "Service
> currently unavailable" if the test has expired which can be annoying.
> I suggest that you turn these tests off.

> After the "PASS" result, the timestamps for the expired tests will
> be set to 'now', and those tests will be skipped until the timestamps
> expire, or until the postscreen cache is deleted.

> Is it possible that the reboot or 'postfix start' removes the
> postscreen cache, as in: "rm -f $data_directory/*' or even 'rm -rf
> $data_directory'?

>         Wietse


Yes, all three were present:
 
postscreen_bare_newline_enable = yes
postscreen_non_smtp_command_enable = yes
postscreen_pipelining_enable = yes

I have removed those.

I don't see any evidence of the postscreen cache being removed at any stage.
There were 230-odd entries in there when I ran the postmap -s, shortly after the reboot.
 
Thanks Wietse,
Phil