Display relevant message-id for all postfix log lines

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

Display relevant message-id for all postfix log lines

sandeep pawar
Hi, 

I am using multiple postfix mta instance for internal relaying purpose. I am sending postfix logs to ELK and was wondering if it would be possible to display message-id in each log line. This could help in various kind of searches.

Is there any configuration which can be tweaked to for custom logging.

Thanks
Sandy
Reply | Threaded
Open this post in threaded view
|

Re: Display relevant message-id for all postfix log lines

Rob McGee
On 2021-04-07 09:25, sandeep pawar wrote:
> I am using multiple postfix mta instance for internal relaying
> purpose. I am sending postfix logs to ELK and was wondering if it
> would be possible to display message-id in each log line. This
> could help in various kind of searches.

Note that the message body does not exist until the SMTP DATA
command has completed.  (Yes, headers are included here.)  So
anything logged before DATA cannot know the Message-Id: header.

> Is there any configuration which can be tweaked to for custom
> logging.

Not that I know of, and the above limitation is unavoidable in
Postfix.  Your workaround would be some script to post-process
your logs.
--
   http://rob0.nodns4.us/
Reply | Threaded
Open this post in threaded view
|

Re: Display relevant message-id for all postfix log lines

Bill Cole-3
In reply to this post by sandeep pawar
On 7 Apr 2021, at 10:25, sandeep pawar wrote:

> Hi,
>
> I am using multiple postfix mta instance for internal relaying
> purpose. I
> am sending postfix logs to ELK and was wondering if it would be
> possible to
> display message-id in each log line. This could help in various kind
> of
> searches.

As Rob McGee noted, the message-id is a part of message data and can't
be known by Postfix until the message data has been transferred, i.e.
the end of the DATA stage. It also may not exist in a message when
received, as it is not a mandatory header.

Postfix also uses (and logs) a "queue ID" which is distinct from the
message-id and can be created for a transaction before DATA, because it
is unique to a message that is or will be in the Postfix queue. By
default, Postfix does not create a queue ID until it has one valid
recipient, logging some events with 'NOQUEUE' where appropriate. To make
Postfix create that ID at the MAIL FROM stage, you can set
smtpd_delay_open_until_valid_rcpt to 'no'. You can use that ID
(typically 10 hex digits) to correlate log lines associated with one
SMTP transaction.

Note that by default the queue ID is unique enough in practice but is
not absolutely guaranteed to be unique over extended periods. I have
seen one case of an ID repeating in the same day on a very busy Postfix
machine.  If you want absolutely unique queue IDs you can set
enable_long_queue_ids to 'yes' and get a longer ID (typically 16
alphanumeric characters) which can never be repeated. With that you also
get monotonically increasing queue IDs.

However, Postfix will always log some lines without any easy means of
correlation to a message. Any event before a MAIL FROM command has been
accepted or after a RSET has occurred is logically distinct from any
particular message, because multiple messages can be sent on one
connection. Any correlation of log lines for Postfix must recognize the
hierarchical nature of how SMTP is handled by Postfix and of how SMTP
works. Each smtpd process can handle multiple connections, each
connection can contain multiple SMTP transactions, and each SMTP
transaction can have multiple recipient addresses.

> Is there any configuration which can be tweaked to for custom logging.

Nothing beyond the documented *_loglevel parameters related to TLS
logging which are documented in the postconf(5) man page. You can get
spectacularly verbose logs with '-v' options to Postfix components, but
that is usually not worth the noise and the formt of individual log
lines is fixed.

One way to get single log lines with everything interesting about a
message is to run a milter that can do that. For example: I use
MIMEDefang, which can execute arbitrary Perl at each stage of the milter
protocol and also has built-in logging utilities. On my personal system,
I log a single huge line at the end of each transaction with all of the
transaction parameters, the SpamAssassin score, and even the Subject.

--
Bill Cole
[hidden email] or [hidden email]
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Not Currently Available For Hire