postscreen -> client hangup unexpectedly -> PASS NEW ?? ..odd?
Amedeo Rinaldo
ciao a tutti ;)
i'm finally learning postscreen (..ahh.. find the time) and i'm trying
to fine tune the entire system.. and myself :)
I was wondering if the following behaviour is due to a my-setup missing
parameter or to a my mistake/misunderstanding in reading the manual ..
before, some details:
#######################################################
- debian squeeze
- postfix 2.8.2
# postconf -n | egrep postscreen
postscreen_bare_newline_action = ignore
postscreen_bare_newline_enable = yes
postscreen_greet_action = enforce
postscreen_greet_banner = pre-greet____please-wait
postscreen_greet_wait = ${stress?2}${stress:8}s
postscreen_non_smtp_command_action = drop
postscreen_non_smtp_command_enable = yes
postscreen_pipelining_action = enforce
postscreen_pipelining_enable = yes
#######################################################
now, logs lines of what i mean:
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
Apr 8 03:28:46 mx20 postfix/postscreen[16419]: CONNECT from
[190.135.213.150]:18780
Apr 8 03:28:55 mx20 postfix/postscreen[16419]: NOQUEUE: reject: RCPT
from [190.135.213.150]:18780: 450 4.3.2 Service currently unavailable;
from=<no-re...@job.de>, to=<eb...@validdomain.com>, proto=ESMTP,
helo=<anteldata.net.uy>
Apr 8 03:28:55 mx20 postfix/postscreen[16419]: HANGUP after 1.6 from
[190.135.213.150]:18780 in tests after SMTP handshake
Apr 8 03:28:55 mx20 postfix/postscreen[16419]: PASS NEW
[190.135.213.150]:18780
Apr 8 03:28:55 mx20 postfix/postscreen[16419]: DISCONNECT
[190.135.213.150]:18780
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
PASS NEW ?? ..infact a second later:
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
Apr 8 03:29:37 mx20 postfix/postscreen[16419]: CONNECT from
[190.135.213.150]:19436
Apr 8 03:29:37 mx20 postfix/postscreen[16419]: PASS OLD
[190.135.213.150]:19436
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
If the client didn't close properly the connection, is the intended
behaviour to 'PASS NEW' that client ? Odd, i expected postscreen to
repeat tests the next time the client connects.
Thank for your time ..i love postfix but, maybe, my english doesn't love
me so much to make me understand the *carefully written* documentation ;-)
bye..
Amedeo Rinaldo
--------------
Una volta eliminato l'impossibile, quello che resta, per improbabile che
sia, deve essere la verità (Sherlock Holmes)
Noel Jones
The client connects.
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: NOQUEUE:
> reject: RCPT from [190.135.213.150]:18780: 450 4.3.2 Service
> currently unavailable; from=<no-re...@job.de>,
> to=<eb...@validdomain.com>, proto=ESMTP, helo=<anteldata.net.uy>
postscreen tests the connection and issues a reject with a 450
"try again" code. At this point, the client has done
everything postscreen requires and testing is complete.
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: HANGUP after
> 1.6 from [190.135.213.150]:18780 in tests after SMTP handshake
The client disconnects after the reject from postscreen.
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: PASS NEW
> [190.135.213.150]:18780
The client was well-behaved and was added to the PASS list.
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: DISCONNECT
> [190.135.213.150]:18780
postscreen ends the session.
Looks OK to me. Consider adding some postscreen_dnsbl_sites
such as zen.spamhaus.org to reject unwanted mail from sites
that pass the protocol tests.
-- Noel Jones
Sahil Tandon
> -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
> Apr 8 03:28:46 mx20 postfix/postscreen[16419]: CONNECT from
> [190.135.213.150]:18780
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: NOQUEUE: reject: RCPT
> from [190.135.213.150]:18780: 450 4.3.2 Service currently
> unavailable; from=<no-re...@job.de>, to=<eb...@validdomain.com>,
> proto=ESMTP, helo=<anteldata.net.uy>
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: HANGUP after 1.6 from
> [190.135.213.150]:18780 in tests after SMTP handshake
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: PASS NEW
> [190.135.213.150]:18780
> Apr 8 03:28:55 mx20 postfix/postscreen[16419]: DISCONNECT
> [190.135.213.150]:18780
> -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
>
> PASS NEW ?? ..infact a second later:
From the POSTSCREEN_README:
When a good client passes the deep protocol tests, postscreen(8) adds
the client to the temporary whitelist but it cannot hand off the "live"
connection to a Postfix SMTP server process in the middle of the
session. Instead, postscreen(8) defers mail delivery attempts with a 4XX
status, logs the helo/sender/recipient information, and waits for the
client to disconnect.
The next time the client connects it will be allowed to talk to a
Postfix SMTP server process to deliver its mail.
> -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
> Apr 8 03:29:37 mx20 postfix/postscreen[16419]: CONNECT from
> [190.135.213.150]:19436
> Apr 8 03:29:37 mx20 postfix/postscreen[16419]: PASS OLD
> [190.135.213.150]:19436
> -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
>
> If the client didn't close properly the connection, is the intended
> behaviour to 'PASS NEW' that client ? Odd, i expected postscreen to
> repeat tests the next time the client connects.
In certain situations, some SMTP clients do not send QUIT; this is
logged as a HANGUP but not treated as a protocol test failure. Do not
mistake logging of HANGUP to mean test failure.
--
Sahil Tandon <sa...@FreeBSD.org>
Amedeo Rinaldo
> .. [cut] ..
> postscreen tests the connection and issues a reject with a 450 "try
> again" code. At this point, the client has done everything postscreen
> requires and testing is complete.
> The client was well-behaved and was added to the PASS list.
My error was considering client not 'well-behaving' (see Sahil reply)
> .. Consider adding some postscreen_dnsbl_sites such as
> zen.spamhaus.org to reject unwanted mail from sites that pass the
> protocol tests.
I've alredy done some tests with ..
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
postscreen_dnsbl_threshold = 2
postscreen_dnsbl_sites = zen.spamhaus.org*2 bl.spamcop.net*1
b.barracudacentral.org*1 spamtrap.trblspam.com*1
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
..or simply..
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
postscreen_dnsbl_threshold = 1
postscreen_dnsbl_sites = zen.spamhaus.org
-- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
But i've (obviously) noticed an high increase in dns queries (unbound
local resolver) and checking my logs i've realized that about 80% of
'defer/reject' would be done by less expensive tests (not rbl
dependent). Consider that at the end of my 'accept-chain' i've postfwd2
policy delegation wich selectively score senders (dnsbl|greylist|throttle).
In this scenario i can speed-up well dressed dns senders, reject/defer
tons of bad client with pcre and reduce dnsbl check to the rest. All
this before amavis/SA ..so dns tests are 'reduced twice'.
Actually.. to me.. i think postscreen will be a superb tool to kill
pregreeter but i'm not going to use its dnsbl features.
However, thanks for the hint.. ;) ..have a nice day!
Amedeo Rinaldo
> .. [cut] ..
> logged as a HANGUP but not treated as a protocol test failure. Do not
> mistake logging of HANGUP to mean test failure.
Sahil .. that was exactly what i was missing!!
I've looked at that log lines with the eyes of person who already knowed
that that client is a bad spam sender .. and i've mistaken.
Thanks, have a nice day ..wow it's friday ..so week-end !! ;)
Wietse Venema
> But i've (obviously) noticed an high increase in dns queries (unbound
> local resolver) and checking my logs i've realized that about 80% of
> 'defer/reject' would be done by less expensive tests (not rbl
> dependent). Consider that at the end of my 'accept-chain' i've postfwd2
Why do you believe that postscreen DNSBL lookups are expensive?
They happen in parallel; there are no extra delays.
You can't compare postscreen lookup with smtpd DNSBL lookups. The
lookups by smtpd happen sequentially and for one client at a time
and increase the length of an SMTP session, making Postfix more
vulnerable to overload problems.
With postscreen, DNSBL lookups happen in parallel and for multiple
clients the same time, and making Postfix less vulnerable to overload
problems.
Wietse
Wietse Venema
> Il 08/04/2011 05:47, Sahil Tandon ha scritto:
> > .. [cut] ..
> > In certain situations, some SMTP clients do not send QUIT; this is
> > logged as a HANGUP but not treated as a protocol test failure. Do not
> > mistake logging of HANGUP to mean test failure.
>
> Sahil .. that was exactly what i was missing!!
> I've looked at that log lines with the eyes of person who already knowed
> that that client is a bad spam sender .. and i've mistaken.
I have added a note to the POSTSCREEN_README to clarify this.
Although the README discusses HANGUP in the section "Other errors",
this is an error without punishment.
Wietse
Wietse Venema
> Il 08/04/2011 14:27, Wietse Venema ha scritto:
> > Amedeo Rinaldo:
> >> But i've (obviously) noticed an high increase in dns queries (unbound
> >> local resolver) and checking my logs i've realized that about 80% of
> >> 'defer/reject' would be done by less expensive tests (not rbl
> >> dependent). Consider that at the end of my 'accept-chain' i've postfwd2
> >
> > Why do you believe that postscreen DNSBL lookups are expensive?
> > They happen in parallel; there are no extra delays.
>
> ..i believe 'DNSBL lookups are expensive' ;) when i can reduce them
> (e.g. with the use of well tested PCRE tables.. or selective graylist).
> In the scenario when the client will be rejected by pcre or anyway
> selectively graylisted (and i obviously hope that bad client
> 'only-1_hit-graylisted' will never came back) ..you know.. no further
> dns/dnsbl checks are needed.
postscreen changes the calculation of "cost".
First, postscreen keeps a cache. When a client passes DNSBL tests
once, it won't generate any postscreen DNSBL lookups for an hour
or so (or whatever postscreen_dnsbl_ttl value is configured). When
some stranger connects, they have to wait for pregreet tests anyway,
so DNSBL lookups won't hurt performance-wise.
Second, PCRE and content inspection mechanisms consume CPU time
which increases the length of an SMTP session, meaning you can
handle less mail per unit of time. This is an issue for people
with large PCRE tables or content inspection mechanisms. CIDR
performance is comparably good, though it can be improved.
All this does not mean that postscreen solves all problems, but
the local "cost" of DNSBL lookup is negligible compared with all
the work that Postfix must do once a session is given to an SMTP
server process, especially when you get into things such as
greylisting and other plugins.
Wietse
Amedeo Rinaldo
>> .. [cut] ..
Really intresting point of view, i need to spend more time on it.
About resource consuming .. i have to check/match my resource/snmp
monitoring to better evaluate. I'm now using few (and quite light
resource consuming) pcre rules and they kill about 60-80% of potential
dnsbl-ed senders. I've given a rapid sight at system graphics now and
during the 2 days of my postscreen dnsbl tests i've noticed more dns
look-up and cpus resources pretty unchanged ..
But consider the system flow has not been altered to well integrate
postscreen (only a rapid test); so i'm sure you are right when you say
"postscreen changes the calculation of costs" !
Have someone already done fine check resource consumption comparisons?
I'm going to play more with ..
Ciao e buon week-end!
Amedeo Rinaldo
------------------
Wietse Venema
> Il 08/04/2011 16:06, Wietse Venema ha scritto:
> >> .. [cut] ..
> > postscreen changes the calculation of "cost".
> >.. [cut] ..
>
>
> Really intresting point of view, i need to spend more time on it.
>
> About resource consuming .. i have to check/match my resource/snmp
> monitoring to better evaluate. I'm now using few (and quite light
> resource consuming) pcre rules and they kill about 60-80% of potential
> dnsbl-ed senders. I've given a rapid sight at system graphics now and
> during the 2 days of my postscreen dnsbl tests i've noticed more dns
> look-up and cpus resources pretty unchanged ..
Postfix uses little CPU, so that is not necessarily a good metric.
A better base for comparisons is "latency", the time to complete
operations including (especially) network read and writes.
Smtpd processes work on one thing at a time, which maximizes latency.
Postscreen works on things in parallel, which reduces latency. This
is possible because postscreen does only simple things.
> But consider the system flow has not been altered to well integrate
> postscreen (only a rapid test); so i'm sure you are right when you say
> "postscreen changes the calculation of costs" !
>
> Have someone already done fine check resource consumption comparisons?
> I'm going to play more with ..
>
> Ciao e buon week-end!
Enjouy the weekend.
Wietse