Postfix audit

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

Postfix audit

Rafael Azevedo-4
Hi guys,

We're in an audit process here and this is giving us a headech.

Is there anyway to log the MTA to MTA transactions one per file?

For example, client requests to send a message, the MTA says OK, sends
the message and keep a log of the MTA to MTA transaction.

Thanks in advance.

BR,

Rafael
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

@lbutlr
On Jun 11, 2019, at 7:55 AM, Rafael Azevedo <[hidden email]> wrote:
> Is there anyway to log the MTA to MTA transactions one per file?

You can use rsyslog to log based on the queueid? But queueid could not be a single line.

With rsyslog the trick is to find something unique in the log lines you want.

Maybe 'relay=.*\]:25’?

--
How you have felt, o men of Athens, at hearing the speeches of my
accusers, I cannot tell; but I know that their persuasive words almost
made me forget who I was, such was the effect of the,; and yet they have
hardly spoken a word of truth.

Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

@lbutlr
On Jun 11, 2019, at 8:30 AM, @lbutlr <[hidden email]> wrote:
> Maybe 'relay=.*\]:25’?

Looking at my logs it looks like

'\]:25:’ is enough.

--
...but the senator, while insisting he was not intoxicated, could not
explain his nudity.

Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Rafael Azevedo-4
I need the full SMTP transaction, commands such as EHLO, MAIL FROM:,
RCPT TO:, and DATA...

Em ter, 11 de jun de 2019 às 11:50, @lbutlr <[hidden email]> escreveu:

>
> On Jun 11, 2019, at 8:30 AM, @lbutlr <[hidden email]> wrote:
> > Maybe 'relay=.*\]:25’?
>
> Looking at my logs it looks like
>
> '\]:25:’ is enough.
>
> --
> ...but the senator, while insisting he was not intoxicated, could not
> explain his nudity.
>
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Wietse Venema
Rafael Azevedo:
> I need the full SMTP transaction, commands such as EHLO, MAIL FROM:,
> RCPT TO:, and DATA...

Postfix can log SMTP commands and responses, but not the message
content because that would consume huge amounts of resources.

If you need the entire SMTP session, your options are

- A network-level sniffer (tcpdump -s 0 -w /file/name ...).

- An SMTP-level splitter (configured using Postfix's smtpd_proxy_filter)
that sends one copy of the SMTP stream to an archival server, and
one copy to Postfix itself.

Either way, no turn-key solution.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Rafael Azevedo-4
Hi Wietse,

Could you please give me more details about option 2 (SMTP-level splitter) ?

Thanks in advance.

BR,

Em ter, 11 de jun de 2019 às 12:37, Wietse Venema
<[hidden email]> escreveu:

>
> Rafael Azevedo:
> > I need the full SMTP transaction, commands such as EHLO, MAIL FROM:,
> > RCPT TO:, and DATA...
>
> Postfix can log SMTP commands and responses, but not the message
> content because that would consume huge amounts of resources.
>
> If you need the entire SMTP session, your options are
>
> - A network-level sniffer (tcpdump -s 0 -w /file/name ...).
>
> - An SMTP-level splitter (configured using Postfix's smtpd_proxy_filter)
> that sends one copy of the SMTP stream to an archival server, and
> one copy to Postfix itself.
>
> Either way, no turn-key solution.
>
>         Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Wietse Venema
Wietse:
> If you need the entire SMTP session, your options are
>
> - A network-level sniffer (tcpdump -s 0 -w /file/name ...).
>
> - An SMTP-level splitter (configured using Postfix's smtpd_proxy_filter)
> that sends one copy of the SMTP stream to an archival server, and
> one copy to Postfix itself.
>
> Either way, no turn-key solution.

Rafael Azevedo:
> Hi Wietse,
> Could you please give me more details about option 2 (SMTP-level splitter) ?

This is work that Viktor Dukhovni (also on this mailing list) did
some 10+ years ago.

The basic idea is a small "y" splitter that is configured as a
content filter (using smtpd_proxy_filter or content_filter). This
receives SMTP commands from Postfix, and connects to Postfix like
any content filter does, but it also connects to an achive server.

The splitter copies its SMTP command inputs to the achive server,
and then to the after-filter Postfix SMTP server. A special case
is the 'end-of-data' stage: here, the splitter sends '.' to the
archive server, and only if the archive server responds with a 2XX
status, the splitter sends the '.' to the after-filter Postfix SMTP
server. Otherwise the splitter just closes the Postfix connection.

I did not build this myself, so I have no details.

`       Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Viktor Dukhovni
> On Jun 11, 2019, at 1:31 PM, Wietse Venema <[hidden email]> wrote:
>
> This is work that Viktor Dukhovni (also on this mailing list) did
> some 10+ years ago.
>
> The basic idea is a small "y" splitter that is configured as a
> content filter (using smtpd_proxy_filter or content_filter). This
> receives SMTP commands from Postfix, and connects to Postfix like
> any content filter does, but it also connects to an achive server.
>
> The splitter copies its SMTP command inputs to the achive server,
> and then to the after-filter Postfix SMTP server. A special case
> is the 'end-of-data' stage: here, the splitter sends '.' to the
> archive server, and only if the archive server responds with a 2XX
> status, the splitter sends the '.' to the after-filter Postfix SMTP
> server. Otherwise the splitter just closes the Postfix connection.
>
> I did not build this myself, so I have no details.

My code for this was never open-sourced, but someone else may have
released something similar since then.  It may be worth noting
that if one just wants to log the protocol chatter, and not the
message content, one does not need a Y proxy.  It suffices to
have a simple linear SMTP proxy that logs the commands.

Mind you, in either case the commands logged would be *internal*
traffic *within* Postfix, not commands received from or sent to
external systems.

I really don't see what SMTP command logging has to do with an
audit.  This sounds most peculiar.

My unreleased code did log the message "MIME skeleton",
consisting of the primary headers, all MIME headers and
nested message headers.  This was useful in understanding
what sort of content was traversing the MTA.  Unlike the
SMTP commands, the message content is largely the same
regardless of whether it is captured coming in, on an
internal hop (simple with content_filter), or going out.

--
--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Rafael Azevedo-4
What we need is a complete conversation between the servers.

We're being requested to give the detailed messages between the
servers to validate the message delivery.

This would be an example of the log needs:

2019-06-12 12:44:47 SERVER -> CLIENT: 220 indus.server.net ESMTP Postfix
2019-06-12 12:44:47 CLIENT -> SERVER: EHLO smtp1.domain.com
2019-06-12 12:44:47 SERVER -> CLIENT: 250-indus.server.net
                                      250-PIPELINING
                                      250-SIZE 2048000
                                      250-VRFY
                                      250-ETRN
                                      250-STARTTLS
                                      250-AUTH LOGIN PLAIN
                                      250-AUTH=LOGIN PLAIN
                                      250-ENHANCEDSTATUSCODES
                                      250-8BITMIME
                                      250 DSN
2019-06-12 12:44:47 CLIENT -> SERVER: STARTTLS
2019-06-12 12:44:47 SERVER -> CLIENT: 220 2.0.0 Ready to start TLS
2019-06-12 12:44:47 CLIENT -> SERVER: EHLO smtp1.domain.com
2019-06-12 12:44:47 SERVER -> CLIENT: 250-indus.server.net
                                      250-PIPELINING
                                      250-SIZE 2048000
                                      250-VRFY
                                      250-ETRN
                                      250-AUTH LOGIN PLAIN
                                      250-AUTH=LOGIN PLAIN
                                      250-ENHANCEDSTATUSCODES
                                      250-8BITMIME
                                      250 DSN
2019-06-12 12:44:47 CLIENT -> SERVER: AUTH LOGIN
2019-06-12 12:44:47 SERVER -> CLIENT: 334 VXNlcm5hbWU6
2019-06-12 12:44:47 CLIENT -> SERVER: RElFR09MQUNPUlRFQEhPVE1BSUwuY29t
2019-06-12 12:44:47 SERVER -> CLIENT: 334 UGFzc3dvcmQ6
2019-06-12 12:44:47 CLIENT -> SERVER: NTJiNmI1
2019-06-12 12:44:47 SERVER -> CLIENT: 235 2.7.0 Authentication successful
2019-06-12 12:44:47 CLIENT -> SERVER: MAIL FROM:
2019-06-12 12:44:47 SERVER -> CLIENT: 250 2.1.0 Ok
2019-06-12 12:44:47 CLIENT -> SERVER: RCPT TO:
2019-06-12 12:44:47 SERVER -> CLIENT: 250 2.1.5 Ok
2019-06-12 12:44:47 CLIENT -> SERVER: DATA
2019-06-12 12:44:47 SERVER -> CLIENT: 354 End data with .
2019-06-12 12:44:47 CLIENT -> SERVER: Date: Wed, 12 Jun 2019 09:44:47 -0300
2019-06-12 12:44:47 CLIENT -> SERVER: To: [hidden email]
2019-06-12 12:44:47 CLIENT -> SERVER: From: User
2019-06-12 12:44:47 CLIENT -> SERVER: Subject: Email test
2019-06-12 12:44:47 CLIENT -> SERVER: Message-ID:
<[hidden email]>
2019-06-12 12:44:47 CLIENT -> SERVER: X-Mailer: IA-Transactional
2019-06-12 12:44:47 CLIENT -> SERVER: MIME-Version: 1.0
2019-06-12 12:44:47 CLIENT -> SERVER: Content-Type: text/html; charset=utf-8
2019-06-12 12:44:47 CLIENT -> SERVER: Content-Transfer-Encoding: 8bit
2019-06-12 12:44:47 CLIENT -> SERVER:
2019-06-12 12:44:47 CLIENT -> SERVER: This is a test message.
2019-06-12 12:44:47 CLIENT -> SERVER:
2019-06-12 12:44:47 CLIENT -> SERVER: .
2019-06-12 12:44:47 SERVER -> CLIENT: 250 2.0.0 Ok: queued as C8C42209B5
2019-06-12 12:44:47 CLIENT -> SERVER: QUIT
2019-06-12 12:44:47 SERVER -> CLIENT: 221 2.0.0 Bye


This were taken from PHPMailer DEBUG mode. Its pretty much the same
info we need, but instead of using phpmailer, grabbing from postfix
conversations.

Any possibility here?

Thanks in advance.

BR,

Rafael
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Jon Radel

On 6/12/19 8:51 AM, Rafael Azevedo wrote:
> We're being requested to give the detailed messages between the
> servers to validate the message delivery.
And it's allowable to have the MTA on one side do the data collection?
If I were your auditor, I'd know that it would be almost impossible for
you to demonstrate that any data subverted by the MTA was subverted
strictly after the audit data was collected. If this is a serious
requirement, I'd be looking at RMON probes on all network connections on
the MTA hardware, with data analyzed by something that has no
commonality with the postfix codebase.

Luckily I'm not your auditor, have no idea what standards you're trying
to meet, and so YMMV.

--Jon Radel

Network Infrastructure Lead
Folio Financial, Inc.
8180 Greensboro Drive, 8th Floor
McLean, VA 22102
(T) 703-245-4844
(M) 703-861-5128
(E) [hidden email]
www.folioinvesting.com

Please do not use e-mail to transmit orders for securities or for other time-sensitive messages. Securities products and services are offered through Folio Investments, Inc. and are subject to investment risk, including the possible loss of principal. Member FINRA/SIPC. Folio Investments, Inc. and First Affirmative Financial Network, LLC are affiliates. This e-mail message and any files transmitted with it are confidential, intended only for the person(s) to whom this e-mail message is addressed. If you have received this e-mail message in error, please notify the sender immediately by telephone or e-mail and destroy the original message without making a copy. This e-mail is subject to review, retrieval, archiving and disclosure by Folio to third parties.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Wietse Venema
In reply to this post by Rafael Azevedo-4
Rafael Azevedo:
> What we need is a complete conversation between the servers.
>
> We're being requested to give the detailed messages between the
> servers to validate the message delivery.
>
> This would be an example of the log needs:
>
> 2019-06-12 12:44:47 SERVER -> CLIENT: 220 indus.server.net ESMTP Postfix

If you want to log all inputs/responses between a remote SMTP client
and a local Postfix server, then that is not built into Postfix.
Use tcpdump plus a tool to convert packets into sessions.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Viktor Dukhovni
In reply to this post by Rafael Azevedo-4
On Wed, Jun 12, 2019 at 09:51:45AM -0300, Rafael Azevedo wrote:

> We're being requested to give the detailed messages between the
> servers to validate the message delivery.

One can usually push back on what appear to be misguided requests
from auditors.  I fail to see the point of this request.  The SMTP
commands sent by clients are of precious little interest.  The
message content can be captured downstream, via always_bcc or
recipient_bcc_maps.  What is the point of the exercise?

Are the auditors asking to do this on an ongoing basis even after
the audit, or just during the audit?  Surely there's another way
to address whatever underlying need is driving this request, or
even set the underlying issue aside as an accepted risk.

--
        Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Rafael Azevedo-4
Hi guys,

Its not the same result between the final client and the server.

Its the communication between the servers.

[client] >>> [server] >>> [final destination's server]

So this is the part they want me to store:

[server] > EHLO > MAIL FROM > RCPT TO > DATA > RESULT (ACCEPTED OR
REJECTED)    [final destination's server]

They need to have the confirmation of the acceptance of the message by
the final destination's provider.


Em qua, 12 de jun de 2019 às 15:19, Viktor Dukhovni
<[hidden email]> escreveu:

>
> On Wed, Jun 12, 2019 at 09:51:45AM -0300, Rafael Azevedo wrote:
>
> > We're being requested to give the detailed messages between the
> > servers to validate the message delivery.
>
> One can usually push back on what appear to be misguided requests
> from auditors.  I fail to see the point of this request.  The SMTP
> commands sent by clients are of precious little interest.  The
> message content can be captured downstream, via always_bcc or
> recipient_bcc_maps.  What is the point of the exercise?
>
> Are the auditors asking to do this on an ongoing basis even after
> the audit, or just during the audit?  Surely there's another way
> to address whatever underlying need is driving this request, or
> even set the underlying issue aside as an accepted risk.
>
> --
>         Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Viktor Dukhovni
On Wed, Jun 12, 2019 at 03:52:10PM -0300, Rafael Azevedo wrote:

> Its the communication between the servers.
>
> [client] >>> [server] >>> [final destination's server]
>
> So this is the part they want me to store:
>
> [server] > EHLO > MAIL FROM > RCPT TO > DATA > RESULT (ACCEPTED OR
> REJECTED)    [final destination's server]
>
> They need to have the confirmation of the acceptance of the message by
> the final destination's provider.

The final confirmation "RESULT" is logged by Postfix in the
postfix/smtp log entry.  For example (with "--->" in front of the
"RESULT" text):

    Jun 12 14:18:35 amnesiac postfix/smtp[6184]: CE26572115:
        to=<[hidden email]>, relay=mail.cloud9.net[168.100.1.4]:25,
        delay=4.3, delays=0.03/0.02/0.34/3.9, dsn=2.0.0, status=sent
  --->  (250 2.0.0 Ok: queued as 119D933B042)

The "RCPT TO" is in the "to=" field, and the "MAIL FROM" is in the
associated qmgr log entry:

    Jun 12 14:18:30 amnesiac postfix/qmgr[61815]: CE26572115:
        from=<[hidden email]>, size=1528, nrcpt=1
        (queue active)

The rest they don't need.  Postfix default logging is sufficient
to track messages and determine delivery success/failure without
jumping through hoops with SMTP session logging.

--
        Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Rafael Azevedo-4
Thank you Viktor,

We already have that log, but they're asking for additional confirmation.

Thanks in advance.

Em qua, 12 de jun de 2019 às 16:11, Viktor Dukhovni
<[hidden email]> escreveu:

>
> On Wed, Jun 12, 2019 at 03:52:10PM -0300, Rafael Azevedo wrote:
>
> > Its the communication between the servers.
> >
> > [client] >>> [server] >>> [final destination's server]
> >
> > So this is the part they want me to store:
> >
> > [server] > EHLO > MAIL FROM > RCPT TO > DATA > RESULT (ACCEPTED OR
> > REJECTED)    [final destination's server]
> >
> > They need to have the confirmation of the acceptance of the message by
> > the final destination's provider.
>
> The final confirmation "RESULT" is logged by Postfix in the
> postfix/smtp log entry.  For example (with "--->" in front of the
> "RESULT" text):
>
>     Jun 12 14:18:35 amnesiac postfix/smtp[6184]: CE26572115:
>         to=<[hidden email]>, relay=mail.cloud9.net[168.100.1.4]:25,
>         delay=4.3, delays=0.03/0.02/0.34/3.9, dsn=2.0.0, status=sent
>   --->  (250 2.0.0 Ok: queued as 119D933B042)
>
> The "RCPT TO" is in the "to=" field, and the "MAIL FROM" is in the
> associated qmgr log entry:
>
>     Jun 12 14:18:30 amnesiac postfix/qmgr[61815]: CE26572115:
>         from=<[hidden email]>, size=1528, nrcpt=1
>         (queue active)
>
> The rest they don't need.  Postfix default logging is sufficient
> to track messages and determine delivery success/failure without
> jumping through hoops with SMTP session logging.
>
> --
>         Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Viktor Dukhovni
> On Jun 12, 2019, at 3:20 PM, Rafael Azevedo <[hidden email]> wrote:
>
> We already have that log, but they're asking for additional confirmation.

Tell them that the "additional" confirmation is neither necessary
nor available.  This is a waste of everyone's time.

The standard logs are quite sufficient.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Stephen Satchell
In reply to this post by Rafael Azevedo-4
On 6/12/19 11:52 AM, Rafael Azevedo wrote:

> Its not the same result between the final client and the server.
>
> Its the communication between the servers.
>
> [client] >>> [server] >>> [final destination's server]
>
> So this is the part they want me to store:
>
> [server] > EHLO > MAIL FROM > RCPT TO > DATA > RESULT (ACCEPTED OR
> REJECTED)    [final destination's server]
>
> They need to have the confirmation of the acceptance of the message by
> the final destination's provider.

As has been suggested before, this is a perfect application for TCPDUMP
with appropriate parameters on your edge server, and a script to
interpret the data.  What you are looking for is source or destination
(your server), port (25/TCP), snaplen of 256, -A to capture the text in
a packet.  A Perl or Python script can parse the data to get what you want.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix audit

Viktor Dukhovni
> On Jun 12, 2019, at 3:40 PM, Stephen Satchell <[hidden email]> wrote:
>
> As has been suggested before, this is a perfect application for TCPDUMP
> with appropriate parameters on your edge server, and a script to
> interpret the data.

Many MTAs nowadays support STARTTLS, and a large fraction of MTA-to-MTA
SMTP traffic is encrypted:

        https://transparencyreport.google.com/safer-email/

If the OP's server has (as it generally should):

        smtp_tls_loglevel = 1
        smtp_tls_security_level = may

or even better, with a local to the MTA host DNSSEC validating
resolver and 127.0.0.1 as the sole nameserver in /etc/resolv.conf:

        smtp_tls_loglevel = 1
        smtp_tls_security_level = dane
        smtp_dns_support_level = dnssec

then much of the SMTP chatter will be inside TLS-encrypted TCP
traffic, and thus not available via "tcpdump".

The auditors should be more concerned with whether STARTTLS is
supported, than whether Postfix logs are somehow misrepresenting
delivery success/failure.  The "additional confirmation" they
seek is unnecessary/pointless.

--
        Viktor.