From: Stefan Foerster on
* Wietse Venema <wietse(a)porcupine.org>:
> On Fri, Dec 04, 2009 at 08:54:01PM +0100, Stefan Foerster wrote:
> > Now, about logging - I'd be really grateful if the existing logging
> > functionality could be extended in a way so that the pre-queue
> > content filter's response is logged.
> >
> > I know that it is actually the content filter's job to log what it did
> > during an ESMTP transaction, but I think if Postfix logged the
> > filter's response, correlating logs would be much easier.
>
> Like this?
>
> Dec 5 20:15:25 server postfix/smtpd[16712]: proxy-accept:
> END-OF-MESSAGE: 250 2.0.0 Ok: queued as 91BE3547AFE;
> from=<sender(a)example.com> to=<recipient(a)example.com> proto=ESMTP
> helo=<client.example.com>
>
> (with the same form for proxy-reject at END-OF-MESSAGE; the format
> of the reject message would be consistent with other Postfix reject
> messages.)

This seems to work perfectly well for me (in a homegrown test
environment):

Dec 6 12:43:40 vmout postfix-submission/smtpd[7323]: proxy-reject:
END-OF-MESSAGE: 554 5.7.0 Reject, id=11912-03 - INFECTED:
Eicar-Test-Signature; from=<cite+root=rac1.vm.cite.lan(a)incertum.net>
to=<cite(a)incertum.net> proto=ESMTP helo=<rac1.vm.cite.lan>


A note on the effectivness of postscreen(8) and the "speed_adjust"
feature from some "real" servers:

1. Out of all connections which were dropped during the PREGREET
stage, 1'199'445 were listed in one of the DNSBLs in use here, saving
about 4.8 million DNS lookups. If there's any interest, I can provide
some plots once I got a few weeks of data.

2. The number of SMTP proxy processes busy talking to Postfix went
down from 16.44 to 8.73 (5s resolution) - that's a completely
unexpected result, possibly flawed by the small data sample. I'll
verify this again once I got a full month's data.

Thanks to you and any other developer who has contributed in those two
features.


Stefan

From: Mark Martinec on
Wietse Venema <wietse(a)porcupine.org>:
> Like this?
> Dec 5 20:15:25 server postfix/smtpd[16712]: proxy-accept:
> END-OF-MESSAGE: 250 2.0.0 Ok: queued as 91BE3547AFE;
> from=<sender(a)example.com> to=<recipient(a)example.com> proto=ESMTP
> helo=<client.example.com>
> (with the same form for proxy-reject at END-OF-MESSAGE; the format
> of the reject message would be consistent with other Postfix reject
> messages.)

Works perfectly, thank you!


On Sunday 06 December 2009 13:11:16 Stefan Foerster wrote:
> 2. The number of SMTP proxy processes busy talking to Postfix went
> down from 16.44 to 8.73 (5s resolution) - that's a completely
> unexpected result, possibly flawed by the small data sample.
> I'll verify this again once I got a full month's data.

A drop in the number of necessary content filtering processes
is to be expected, and is in fact the main reason for the
smtpd_proxy_options=speed_adjust feature. Very useful / indispensable
in the pre-queue filtering setup.

Mark

From: Stefan =?utf-8?Q?F=C3=B6rster?= on
* Mark Martinec <Mark.Martinec+postfix(a)ijs.si>:
> On Sunday 06 December 2009 13:11:16 Stefan Foerster wrote:
>> 2. The number of SMTP proxy processes busy talking to Postfix went
>> down from 16.44 to 8.73 (5s resolution) - that's a completely
>> unexpected result, possibly flawed by the small data sample.
>> I'll verify this again once I got a full month's data.
>
> A drop in the number of necessary content filtering processes
> is to be expected, and is in fact the main reason for the
> smtpd_proxy_options=speed_adjust feature. Very useful / indispensable
> in the pre-queue filtering setup.

Of course - but not by this magnitude. As I said, I'll verify
mid-December (or perhaps around Christmas).


Stefan