Ambiguous logging of mail senders

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Ambiguous logging of mail senders

Sven Bartscher
Greetings,

recently I stumbled across a log line like this:

Oct 25 10:34:59 hostname postfix/smtpd[12345]: NOQUEUE: reject: RCPT
from client.example[1.2.3.4]: 554 5.7.1 <[hidden email]; [hidden email]>: Relay access
denied; from=<[hidden email]> to=<[hidden email]; [hidden email]> proto=ESMTP
helo=<client.example>

The important part is the "to=<[hidden email]; [hidden email]>". Parsing this to find
out which part is the local-part and which is the domain isn't exactly
trivial, both for me as a human or for a machine automatically parsing
the log. As it turns out, the original address was "[hidden email]; c"@d.com,
but it could have been "[hidden email]; [hidden email]" (i.e. local-part only, without
a domain) just as well. There is no way to know for sure from the log alone.

There are more obscure examples like this:

Aug 29 12:52:50 hostname postfix/smtpd[12345] NOQUEUE: reject: RCPT from
client.example[1.2.3.4]: 554 5.7.1 <host>: Helo command rejected: Access
denied; from=<[hidden email]> to=<[hidden email]> from=<[hidden email]> to=<[hidden email]> proto=ESMTP
helo=<host>

In this case it is not possible to say with certainty, what the envelope
addresses actually are. It can be either of these:

to: "[hidden email]> from=<[hidden email]> to=<[hidden email]" (local-part only, without domain)
from: [hidden email]

or

to: [hidden email]
from: "[hidden email]> to=<[hidden email]> from=<[hidden email]" (local-part only, without domain)

At this point I definitely see no way of exactly knowing, what the
actual email looked like.

Is there some way to configure postfix to log this in a way that is
unambiguously understandable? Otherwise this kinda seems like a bug to
me or at least something I consider worthy of a feature request.

Regards
Sven


signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Ambiguous logging of mail senders

Wietse Venema
Sven Bartscher:

Checking application/pgp-signature: FAILURE
-- Start of PGP signed section.

> Greetings,
>
> recently I stumbled across a log line like this:
>
> Oct 25 10:34:59 hostname postfix/smtpd[12345]: NOQUEUE: reject: RCPT
> from client.example[1.2.3.4]: 554 5.7.1 <[hidden email]; [hidden email]>: Relay access
> denied; from=<[hidden email]> to=<[hidden email]; [hidden email]> proto=ESMTP
> helo=<client.example>
>
> The important part is the "to=<[hidden email]; [hidden email]>". Parsing this to find
> out which part is the local-part and which is the domain isn't exactly
> trivial, both for me as a human or for a machine automatically parsing
> the log. As it turns out, the original address was "[hidden email]; c"@d.com,
> but it could have been "[hidden email]; [hidden email]" (i.e. local-part only, without
> a domain) just as well. There is no way to know for sure from the log alone.

Agreed. One would have to know that Postfix logs the 'internal'
form.

Why does Postfix use the internal form(*)? Because there can be
multiple original forms for the same address, for example using
quotes or backslashes. And having multiple forms for the same thing
is bad if one wants to implement, for example, SMTP access policies.

Why does Postfix not log the original form in addition to the
internal form? That would require code changes to everything code
that logs an envelope sender or recipient. It would have to log
both the original form and the form that Postfix uses for table
lookup, otherwise table lookups would be difficult to debug.

I would just configure Postfix to reject the garbage instead of
doing a lot of work to log the garbage unambiguously.

        Wietse

(*) As an aside, Postfix is in a transition from using internal
address forms in lookup tables to using external forms, so that the
tables can handle addresses with whitespace. But it still uses the
unquoted form internally, instead of the original form, to avoid
ambiguity due to quotes or backslashes.
Reply | Threaded
Open this post in threaded view
|

Re: Ambiguous logging of mail senders

Sven Bartscher
Hi,

Am 25.10.19 um 16:34 schrieb Wietse Venema:
> Why does Postfix not log the original form in addition to the
> internal form? That would require code changes to everything code
> that logs an envelope sender or recipient. It would have to log
> both the original form and the form that Postfix uses for table
> lookup, otherwise table lookups would be difficult to debug.

My first intuition on how to fix this, wasn't actually to change the
logging drastically, but to add escaping for characters that usually
have special meaning in the address. As an example

As an example I would log this address

"[hidden email]> from=<[hidden email]> to=<\[hidden email]"@example.com

somewhat like this

to=<[hidden email]\> from=\<[hidden email]\> to=\<\\[hidden email]@example.com>

The first drawback I see with this is, that it's ugly, but I think
that's offset by the benefit, that it's unambiguous.

The second drawback would be that it is not what the internal form
currently looks like. So the log either doesn't directly show what you
have to write in tables, potentially confusing people, but at least to
me that seems better than logging things that are as ambiguous as they
currently are.

> I would just configure Postfix to reject the garbage instead of
> doing a lot of work to log the garbage unambiguously.
Unfortunately that doesn't solve the problem, because rejecting the
mail, doesn't stop the address from showing up in my log.

Regards
Sven


signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Ambiguous logging of mail senders

Wietse Venema
Sven Bartscher:

Checking application/pgp-signature: FAILURE
-- Start of PGP signed section.

> Hi,
>
> Am 25.10.19 um 16:34 schrieb Wietse Venema:
> > Why does Postfix not log the original form in addition to the
> > internal form? That would require code changes to everything code
> > that logs an envelope sender or recipient. It would have to log
> > both the original form and the form that Postfix uses for table
> > lookup, otherwise table lookups would be difficult to debug.
>
> My first intuition on how to fix this, wasn't actually to change the
> logging drastically, but to add escaping for characters that usually
> have special meaning in the address. As an example
>
> As an example I would log this address
>
> "[hidden email]> from=<[hidden email]> to=<\[hidden email]"@example.com
>
> somewhat like this
>
> to=<[hidden email]\> from=\<[hidden email]\> to=\<\\[hidden email]@example.com>

Make the backslash character special when logging the sender in
Postfix reject messages? Bleh.

I would prefer consistency, i.e. always log a sender or recipient
address in proper externalized form.

    from=<"[hidden email]> from=<[hidden email]> to=<\\[hidden email]"@example.com

There is a library function tok822_externalize() for doing the above
conversion. There are not that many places where =<%s> is called
with an address, so this is just some work. This avoids the need
to propagate both address versions through all of Postfix.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Ambiguous logging of mail senders

Sven Bartscher
Hi,

Am 29.10.19 um 00:39 schrieb Wietse Venema:

> Sven Bartscher:
>> My first intuition on how to fix this, wasn't actually to change the
>> logging drastically, but to add escaping for characters that usually
>> have special meaning in the address. As an example
>>
>> As an example I would log this address
>>
>> "[hidden email]> from=<[hidden email]> to=<\[hidden email]"@example.com
>>
>> somewhat like this
>>
>> to=<[hidden email]\> from=\<[hidden email]\> to=\<\\[hidden email]@example.com>
>
> Make the backslash character special when logging the sender in
> Postfix reject messages? Bleh.
>
> I would prefer consistency, i.e. always log a sender or recipient
> address in proper externalized form.
>
>     from=<"[hidden email]> from=<[hidden email]> to=<\\[hidden email]"@example.com
>
> There is a library function tok822_externalize() for doing the above
> conversion. There are not that many places where =<%s> is called
> with an address, so this is just some work. This avoids the need
> to propagate both address versions through all of Postfix.
That does seem like a sensible way forward. However, after reading your
last message, I was under the impression, that you were opposed to
logging something other than the internal form, because it makes table
lookups harder to debug. Can you clarify your stance on this?

Regards
Sven




signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Ambiguous logging of mail senders

Wietse Venema
Sven Bartscher:

Checking application/pgp-signature: FAILURE
-- Start of PGP signed section.

> Hi,
>
> Am 29.10.19 um 00:39 schrieb Wietse Venema:
> > Sven Bartscher:
> >> My first intuition on how to fix this, wasn't actually to change the
> >> logging drastically, but to add escaping for characters that usually
> >> have special meaning in the address. As an example
> >>
> >> As an example I would log this address
> >>
> >> "[hidden email]> from=<[hidden email]> to=<\[hidden email]"@example.com
> >>
> >> somewhat like this
> >>
> >> to=<[hidden email]\> from=\<[hidden email]\> to=\<\\[hidden email]@example.com>
> >
> > Make the backslash character special when logging the sender in
> > Postfix reject messages? Bleh.
> >
> > I would prefer consistency, i.e. always log a sender or recipient
> > address in proper externalized form.
> >
> >     from=<"[hidden email]> from=<[hidden email]> to=<\\[hidden email]"@example.com
> >
> > There is a library function tok822_externalize() for doing the above
> > conversion. There are not that many places where =<%s> is called
> > with an address, so this is just some work. This avoids the need
> > to propagate both address versions through all of Postfix.
>
> That does seem like a sensible way forward. However, after reading your
> last message, I was under the impression, that you were opposed to
> logging something other than the internal form, because it makes table
> lookups harder to debug. Can you clarify your stance on this?

Many table lookups have been converted to using external form, so
external-form logging would be a better match for troubleshooting.
Exanmples are access, canonical, virtual, and transport lookups.

Instead of tok822_externalize(), quote_822_local() would be more
suitable for the conversion; this function is already used for
generating the access, etc. external-form queries.

        Wietse