postscreen behavior - one CONNECT, 2 REJECTs?

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

postscreen behavior - one CONNECT, 2 REJECTs?

jasonsu
I've added blocking by TLD to my setup.  Right now, it blocks at helo checks.

It's working.

Looking at my logs, EVERY time I get a 'bad TLD' connection, there's always 2 similar reject entries, but only one CONNECT/PASS  For example

        Apr  4 19:55:38 mail01 postfix/postscreen[7444]: CONNECT from [74.63.250.84]:44441 to [198.51.100.29]:25
        Apr  4 19:55:44 mail01 postfix/postscreen[7444]: PASS NEW [74.63.250.84]:44441
        Apr  4 19:55:44 mail01 postfix/psint/smtpd[7450]: connect from g87d686d.darrylloves.science[74.63.250.84]
        Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: EHLO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>
        Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: HELO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>
        Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: disconnect from g87d686d.darrylloves.science[74.63.250.84] helo=0/1 ehlo=0/1 quit=1 commands=1/3

I'm not exactly sure why I'm getting one CONNECT and 2 REJECTs.

Everything seems to work fine otherwise. The bad TLD's rejected ok.  Mail that does pass, I only get one delivered copy of email.
 
Are there actually 2 connections from the sender?  Or should I be looking to something wrong in my configuration?

Jason
Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

Wietse Venema
[hidden email]:

> I've added blocking by TLD to my setup.  Right now, it blocks at helo checks.
>
> It's working.
>
> Looking at my logs, EVERY time I get a 'bad TLD' connection, there's always 2 similar reject entries, but only one CONNECT/PASS  For example
>
> Apr  4 19:55:38 mail01 postfix/postscreen[7444]: CONNECT from [74.63.250.84]:44441 to [198.51.100.29]:25
> Apr  4 19:55:44 mail01 postfix/postscreen[7444]: PASS NEW [74.63.250.84]:44441
> Apr  4 19:55:44 mail01 postfix/psint/smtpd[7450]: connect from g87d686d.darrylloves.science[74.63.250.84]
> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: EHLO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>
> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: HELO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>
> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: disconnect from g87d686d.darrylloves.science[74.63.250.84] helo=0/1 ehlo=0/1 quit=1 commands=1/3
>
> I'm not exactly sure why I'm getting one CONNECT and 2 REJECTs.

The client sent two RCPT TO commands. Why did it try the same
recipient twice? No idea, I didn't write the client code.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

jasonsu
On 04/05/2016 07:08 AM, Wietse Venema wrote:>> I'm not exactly sure why I'm getting one CONNECT and 2 REJECTs.
>
> The client sent two RCPT TO commands. Why did it try the same
> recipient twice? No idea, I didn't write the client code.

I was just looking to make sure I'm not doing something wrong.

Not surprised that some spammer's client is doing something weird!

It didn't dawn on me that a client can send 2 identical commands in a single connection, and still be a legit SMTP transaction.

Thanks.

Jason
Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

Bill Cole-3
In reply to this post by Wietse Venema
On 5 Apr 2016, at 10:08, Wietse Venema wrote:

> [hidden email]:
>> I've added blocking by TLD to my setup.  Right now, it blocks at helo
>> checks.
>>
>> It's working.
>>
>> Looking at my logs, EVERY time I get a 'bad TLD' connection, there's
>> always 2 similar reject entries, but only one CONNECT/PASS  For
>> example
>>
>> Apr  4 19:55:38 mail01 postfix/postscreen[7444]: CONNECT from
>> [74.63.250.84]:44441 to [198.51.100.29]:25
>> Apr  4 19:55:44 mail01 postfix/postscreen[7444]: PASS NEW
>> [74.63.250.84]:44441
>> Apr  4 19:55:44 mail01 postfix/psint/smtpd[7450]: connect from
>> g87d686d.darrylloves.science[74.63.250.84]
>> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject:
>> EHLO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1
>> <g87d686d.darrylloves.science>: Helo command rejected: TLD;
>> proto=SMTP helo=<g87d686d.darrylloves.science>
>> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject:
>> HELO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1
>> <g87d686d.darrylloves.science>: Helo command rejected: TLD;
>> proto=SMTP helo=<g87d686d.darrylloves.science>
>> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: disconnect from
>> g87d686d.darrylloves.science[74.63.250.84] helo=0/1 ehlo=0/1 quit=1
>> commands=1/3
>>
>> I'm not exactly sure why I'm getting one CONNECT and 2 REJECTs.
>
> The client sent two RCPT TO commands. Why did it try the same
> recipient twice? No idea, I didn't write the client code.

I think that's slightly wrong. There is no RCPT.

First rejection is of EHLO, second is of HELO. This is standard client
behavior if the rejection is not deferred to RCPT but actually being
done at EHLO/HELO time : EHLO gets rejected so HELO is (correctly) tried
instead.

With "smtpd_delay_reject = yes" this would be avoided because the
rejection would be deferred to RCPT time.

Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

Noel Jones-2
In reply to this post by jasonsu
On 4/5/2016 9:17 AM, [hidden email] wrote:

> On 04/05/2016 07:08 AM, Wietse Venema wrote:>> I'm not exactly sure why I'm getting one CONNECT and 2 REJECTs.
>>
>> The client sent two RCPT TO commands. Why did it try the same
>> recipient twice? No idea, I didn't write the client code.
>
> I was just looking to make sure I'm not doing something wrong.
>
> Not surprised that some spammer's client is doing something weird!
>
> It didn't dawn on me that a client can send 2 identical commands in a single connection, and still be a legit SMTP transaction.
>
> Thanks.
>
> Jason
>


I think this particular instance is because you've set the
non-default non-recommended "smtpd_delay_reject = no".

> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: EHLO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>
> Apr  4 19:55:45 mail01 postfix/psint/smtpd[7450]: NOQUEUE: reject: HELO from g87d686d.darrylloves.science[74.63.250.84]: 554 5.7.1 <g87d686d.darrylloves.science>: Helo command rejected: TLD; proto=SMTP helo=<g87d686d.darrylloves.science>

First the client's EHLO is rejected, then the client retries with HELO.

You may notice other oddities when you use "smtpd_delay_reject =
no", including clients that treat an early reject as temporary
failures and keep retrying.



  -- Noel Jones
Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

jasonsu
Yep, I had

        smtpd_delay_reject=no

set in main.cf

Wondeing WHY I

        "set the non-default non-recommended "smtpd_delay_reject = no"."

looking at my notes, I found

        ...
        With smtpd_delay_reject=no milters always follow built-in restriction processing.

        With smtpd_delay_reject=yes, milters process: connect -> helo/ehlo -> from: before any smtpd_mumble_restrictions are evaluated, and then restrictions starting with "rcpt to:".
        ...

Of course as usual that's not clear enough - NOW - & I can't remember the specific problem I was trying to solve, if any. :-/

I'll set the

        smtpd_delay_reject=yes

and watch that for awhile to see what happens.

Thanks.

Jason
Reply | Threaded
Open this post in threaded view
|

Re: smtpd_delay_reject behavior (WAS: postscreen behavior - one CONNECT, 2 REJECTs?)

jasonsu
> I'll set the
>
> smtpd_delay_reject=yes
>
> and watch that for awhile to see what happens.


Okay, I remembered what I was *trying* to make sure happened by setting

        smtpd_delay_reject=no

For now I'm trying to do everything stepwise and more-or-less separated in Postfix config, until I get a good handle on flow.  Later on I'll clean it up and streamline it.

Right now, after postscreen, I pass email to a prequeue isntance of amavis

SMTPd-only SPF + DKIM checks are done here.

Amavis passes back to a postfix smtpd instance which I set up with

        -o smtpd_milters=inet:127.0.0.1:8893
        -o non_smtpd_milters=inet:127.0.0.1:8893
        -o content_filter=amavis:[127.0.0.1]:13003

where my goal is to first pass through an OpenDMARC milter (port 8893), and THEN to a 2nd amavis instance, postqueue, to do content (A/V, A/S) scanning.

I think I set

        smtpd_delay_reject=no

to make sure that that order was preserved.

But TBH I can't convince myself from reading if smtpd_delay_reject has any effect.

So my question is -- does it?

If I set the recommended

        smtpd_delay_reject=yes

in order to 'fix' the original issue here of the "double reject", will the mail still flow through the OpenDMARC milter

        -o smtpd_milters=inet:127.0.0.1:8893
        -o non_smtpd_milters=inet:127.0.0.1:8893

first, and only them if passed, on to the postqueue Amavis?

        -o content_filter=amavis:[127.0.0.1]:13003


Thanks

Jason
Reply | Threaded
Open this post in threaded view
|

Re: postscreen behavior - one CONNECT, 2 REJECTs?

Bill Cole-3
In reply to this post by jasonsu
On 5 Apr 2016, at 10:59, [hidden email] wrote:

> looking at my notes, I found
>
> ...
> With smtpd_delay_reject=no milters always follow built-in restriction
> processing.
>
> With smtpd_delay_reject=yes, milters process: connect -> helo/ehlo ->
> from: before any smtpd_mumble_restrictions are evaluated, and then
> restrictions starting with "rcpt to:".
> ...
>
> Of course as usual that's not clear enough - NOW -

The milter protocol is somewhat analogous to Postfix's native
smtpd_*_restrictions in that each milter is passed a set of session (and
eventually message) attributes at each step of the SMTP conversation and
answers with its judgment of whether and how to proceed. *As I
understand it* (Viktor or Wietse will surely correct me if I
misunderstand) this is not changed by smtpd_delay_reject=yes in the same
way that setting modifies smtpd_*_restrictions action: the milters are
still called and answered at the protocol-defined times in their
specified order and if one tells Postfix to reject a message, that
rejection is immediate. However, as documented, smtpd_delay_reject=yes
delays *evaluation* of  smtpd_{client,helo,sender}_restrictions until
RCPT time, so there is no way to override a pre-RCPT milter rejection
with any sort of exceptions implemented in smtpd_*_restrictions.

Note that this is not purely a Postfix issue. Rejection before RCPT in
some cases can result in some (faulty) clients retrying transactions
which should not be retried. This issue was discovered early in the days
of spam filtering and is part of why smtpd_delay_reject exists. It is
also why some milters (e.g. MIMEDefang) by default do not enable
pre-RCPT action and instead encourage only taking per-RCPT actions at
RCPT time, leaving everything else to the DATA phases.

> & I can't remember the specific problem I was trying to solve, if any.
> :-/

I can't help you there...