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

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/

Re: 450 4.3.2 - Postscreen

[Rob McGee]

On 2021-04-07 11:57, Maurizio Caloro wrote:

Today I have activate postscreen on mailserver, now one email will now
reject but I understood that this

Will be delivered after some time….. "this are like in waiting"


Depends.  There are some transactional mail senders which do not
retry.


Apr  7 18:49:36 ail postfix/postscreen[32484]: NOQUEUE: reject: RCPT
from [40.92.73.101]:47169: 450 4.3.2 Service currently unavailable;
from=jemes.c...@hotmail.com, to=mauri...@domain.ch, proto=ESMTP,
helo=


Microsoft's outbound server farm certainly WILL retry.  I do not
know, however, if they will retry from the same IP address.


Please how long will this action take, or its possible to shorting
this time?


That's entirely up to the sending client.  Most should retry in a
matter of minutes.

The delay can be avoided if the sending client is whitelisted, and
indeed all the Microsoft outbound farm hosts are listed in
list.dnswl.org's whitelist.


Or I need to understood more about this postrscreen?


You definitely do.

You should not have enabled the after-220 tests before you
understand what they do and what they cost you.

http://www.postfix.org/POSTSCREEN_README.html is the primary
reference.

http://rob0.nodns4.us/postscreen.html is my own configuration.  It
includes an example of the aforementioned whitelist feature
( 
http://www.postfix.org/postconf.5.html#postscreen_dnsbl_whitelist_threshold 
).

--
  http://rob0.nodns4.us/

Milter calls based on conditions and deliberate delays

[Ralph Seichter]

Hello list,

I am trying to configure Postfix to process inbound mail in the following
manner:

1. A sender connect to Postfix smtpd to deliver a message.

2. Postfix calls Milters A, B, C. Each of these Milters can either (a)
reject the message, (b) accept the message without changes or (c) add
a new header "X-SomeHeader: SomeValue" and then accept the message.

3. If any of the milters rejects the message (case 2a) Postfix rejects
the delivery attempt in progress with code 5xx.

4. In case 2b (all milters accept without changes) Postfix signals 250
to the sender, terminates the inbound connection, looks up a "next hop"
transport and passes the message to that destination.

The tricky part is case 2c. Messages marked with one or more additional
Headers, and only these messages, need to be passed to a fourth milter D
after a delay (!) of somewhere between 90s and 5m (current estimate).
Milter D then either accepts the message as is or adds yet another new
header before accepting.

As calling milter D depends on the presence and content of headers, I
assume that it might be difficult to achieve the desired behaviour with
built-in Postfix features of a single Postfix instance. I am currently
exploring the idea of writing a transport service which FIFO-queues all
inbound messages for case 2c, delaying them for X seconds before passing
them to a second Postfix instance which talks to milter D.

However, I'd rather use Postfix's own robust mechanisms (perhaps the
deferred queue?) instead of implementing a queing transport from scratch.
Also, I estimate that whatever queue I use will grow to hold approx. 1-5
million messages at peak times, so performance and robustness are key.

If you have ideas that could help me solve this, I'd appreciate you
letting me know.

-Ralph

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

[Bill Cole]

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
b...@scconsult.com or billc...@apache.org
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Not Currently Available For Hire

Re: Milter calls based on conditions and deliberate delays

[Benny Pedersen]

On 2021-04-07 20:10, Ralph Seichter wrote:


If you have ideas that could help me solve this, I'd appreciate you
letting me know.


maybe https://github.com/milter-manager/milter-manager ?

Re: Milter calls based on conditions and deliberate delays

[Wietse Venema]

Ralph Seichter:
> Hello list,
> 
> I am trying to configure Postfix to process inbound mail in the following
> manner:
> 
> 1. A sender connect to Postfix smtpd to deliver a message.
> 
> 2. Postfix calls Milters A, B, C. Each of these Milters can either (a)
> reject the message, (b) accept the message without changes or (c) add
> a new header "X-SomeHeader: SomeValue" and then accept the message.
> 
> 3. If any of the milters rejects the message (case 2a) Postfix rejects
> the delivery attempt in progress with code 5xx.
> 
> 4. In case 2b (all milters accept without changes) Postfix signals 250
> to the sender, terminates the inbound connection, looks up a "next hop"
> transport and passes the message to that destination.
> 
> The tricky part is case 2c. Messages marked with one or more additional
> Headers, and only these messages, need to be passed to a fourth milter D
> after a delay (!) of somewhere between 90s and 5m (current estimate).
> Milter D then either accepts the message as is or adds yet another new
> header before accepting.
> 
> As calling milter D depends on the presence and content of headers, I
> assume that it might be difficult to achieve the desired behaviour with
> built-in Postfix features of a single Postfix instance. I am currently
> exploring the idea of writing a transport service which FIFO-queues all
> inbound messages for case 2c, delaying them for X seconds before passing
> them to a second Postfix instance which talks to milter D.
> 
> However, I'd rather use Postfix's own robust mechanisms (perhaps the
> deferred queue?) instead of implementing a queing transport from scratch.
> Also, I estimate that whatever queue I use will grow to hold approx. 1-5
> million messages at peak times, so performance and robustness are key.
> 
> If you have ideas that could help me solve this, I'd appreciate you
> letting me know.

What problem are you trying to solve? Please describe the problem
(why not deliver mail when it is received), not the solution (labeling
a message, and diverting labeled messages).

Wietse

Re: Milter calls based on conditions and deliberate delays

[Ralph Seichter]

* Wietse Venema:

> What problem are you trying to solve?

Milters A, B and C in my example scenario can trigger asynchronous
actions in backend systems, the results of which become available only
after a delay caused by processing, which takes about 3 minutes. These
results are required by milter D, and it is not feasible to have Postfix
hold the original sender's session in an active state for this amount of
time.

My idea is to hold the affected messages in a FIFO-queue-like component
for a configurable amount of time, long enough to ensure that the
backend processing has finished when milter D is called. Other than
inducing a delay, the transport queue can be "dumb". That whay, I see no
need for any form of synchronisation between Postfix and the third-party
backend processes.

-Ralph

450 4.3.2 - Postscreen

[Maurizio Caloro]

 

Hello

Today I have activate postscreen on mailserver, now one email will now
reject but I understood that this

Will be delivered after some time... "this are like in waiting"

 

Apr  7 18:49:36 ail postfix/postscreen[32484]: NOQUEUE: reject: RCPT from
[40.92.73.101]:47169: 450 4.3.2 Service currently unavailable;
from=jemes.c...@hotmail.com  ,
to=mauri...@domain.ch  , proto=ESMTP,
helo=

 

Please how long will this action take, or its possible to shorting this
time?

 

Or I need to understood more about this postrscreen?

Thanks

Re: Milter calls based on conditions and deliberate delays

[John Stoffel]

> "Ralph" == Ralph Seichter  writes:

Ralph> * Wietse Venema:
>> What problem are you trying to solve?

Ralph> Milters A, B and C in my example scenario can trigger
Ralph> asynchronous actions in backend systems, the results of which
Ralph> become available only after a delay caused by processing, which
Ralph> takes about 3 minutes. These results are required by milter D,
Ralph> and it is not feasible to have Postfix hold the original
Ralph> sender's session in an active state for this amount of time.

So what happens if you get 1,000 emails coming into your system?  This
smells like a Denial of Service problem for you and your incoming
email.  That 3 minutes is a *long* time to wait for a reply on your
milters.

Ralph> My idea is to hold the affected messages in a FIFO-queue-like
Ralph> component for a configurable amount of time, long enough to
Ralph> ensure that the backend processing has finished when milter D
Ralph> is called. Other than inducing a delay, the transport queue can
Ralph> be "dumb". That whay, I see no need for any form of
Ralph> synchronisation between Postfix and the third-party backend
Ralph> processes.

So basically you want to accept all emails, feed them through a chain
of milters which take forever to process, and then deliver or not?

Are you're milters filtering out attachements?  Or looking inside
attachments for spam and/or viruses?

Can you go up a level and talk about the problem you're trying to
solve, not HOW you're trying to solve it.  What email threat are you
looking to solve?

John

Re: Milter calls based on conditions and deliberate delays

[Wietse Venema]

Ralph Seichter:
> * Wietse Venema:
> 
> > What problem are you trying to solve?
> 
> Milters A, B and C in my example scenario can trigger asynchronous
> actions in backend systems, the results of which become available only
> after a delay caused by processing, which takes about 3 minutes. These
> results are required by milter D, and it is not feasible to have Postfix
> hold the original sender's session in an active state for this amount of
> time.

Use milter_header_checks to trigger a FILTER action. This will divery
a message to a content_filter that upon re-injection into
Postfix 

internet -> smtpd(with milters A-C) -> cleanup -> queue

If the message has no magical headeer, it is delivered as usual.

queue -> smtp -> network
queue -> local -> mailbox

Otherwise it is sent though a content filter than can be empty

queoe -> smtp(with large timeout) -> 
smtpd(with milter D, with large milter timeout) -> cleanup -> queue

and then it is delivered as usual.

This requires that Milter D blocks until the nedessary info is available.

Wietse

Re: Milter calls based on conditions and deliberate delays

[Wietse Venema]

Wietse Venema:
> Ralph Seichter:
> > * Wietse Venema:
> > 
> > > What problem are you trying to solve?
> > 
> > Milters A, B and C in my example scenario can trigger asynchronous
> > actions in backend systems, the results of which become available only
> > after a delay caused by processing, which takes about 3 minutes. These
> > results are required by milter D, and it is not feasible to have Postfix
> > hold the original sender's session in an active state for this amount of
> > time.

Edited for clarity, and one additional suggestion:

> Use milter_header_checks to trigger a FILTER action. 
> 
> internet -> smtpd(with milters A-C) -> cleanup -> queue
> 
> If the message has no magical headeer, it is delivered as usual.
> 
> queue -> smtp -> network
> queue -> local -> mailbox
> 
> Otherwise it is sent though a content filter than can be empty
> 
> queoe -> smtp(with large timeout) -> 
>   smtpd(with milter D, with large milter timeout) -> cleanup -> queue
> 
> and then it is delivered as usual.
> 
> This requires that Milter D blocks until the nedessary info is available.

Perhaps better, Milter D defers the message immrediately, and Postfix retries 
a few minutes later, until the necessary data is available.

You may need to tweak queue_run_delay, minimal_backoff_time and
maximal_backoff_time. 

Wietse

Re: Bad net/mask pattern

[Norton Allen]

On 4/6/2021 11:54 AM, Wietse Venema wrote:

Norton Allen:

One must always announce their failings before they can see them.

Postfix did not like the '00' for the 4th octet.

The address was rejected by the inet_pton() system library function.
I have made the warning more specific.

Example:

warning: cidr map /tmp/x.cidr, line 1: bad network value in "1.2.3.00/28": 
skipping this rule
Thanks, that should help. The real trick in the heat of the moment is to 
calm down and read the errors carefully.