Score:2

Postfix - Discarding EHLO Keywords Duplicate Log Entries

cn flag

Ubuntu 20.04
Postfix 3.4

For each message received by my Postfix I see the following two entries:

Mar  8 16:34:42 mail postfix/smtpd[863775]: discarding EHLO keywords: ETRN DSN
Mar  8 16:34:42 mail postfix/smtpd[863775]: discarding EHLO keywords: ETRN DSN

My configuration...

me@mail:/etc/postfix$ postconf -n |grep smtpd_discard_ehlo_keywords
smtpd_discard_ehlo_keywords = ETRN, DSN

smtpd_discard_ehlo_keywords does not exist in master.cf, but even if it did that overrides - not additive - main.cf, correct?

How can I stop this behavior or is it normal (albeit odd)?

Thanks.

anx avatar
fr flag
anx
I could imagine setups where specifying it once, globally, applies to two separate `smtpd` services. Adding `-o syslog_name=example` below additional `smtpd` lines in `master.cf` would clarify such situations.
user1801810 avatar
cn flag
I think I see where you're going with that and made your suggested edit. The two entries are now `...mail example/smtpd...` instead of how I previously noted. If your logic played out I think we should have seen an entry with the previous label (`postfix/smtpd`) as well as an entry with `example/smtpd`, correct?
Score:3
fr flag
anx

Its harmless - actually, the norm, in all but rare special cases: Almost all clients will send EHLO once to coax the server into revealing that yes, of course, it will accept the STARTTLS workaround to upgrade the existing connection to a secure channel. And then they will have to send EHLO again because the server is not allowed to reuse anything received from the preceding insecure channel:

Upon completion of the TLS handshake, the SMTP protocol is reset to the initial state (the state in SMTP after a server issues a 220 service ready greeting).

(Well, at least its supposed to. There were a few very unfortunate bugs around this, allowing malicious third-parties insert commands in an believed-to-be secure session.)

It is even possible that a misconfigured client send EHLO more often than twice, not necessarily hampering actual deliveries. I have seen that happen with broken intercepting (MitM) firewalls.


You can make the fact that the two messages refer to mostly-separate SMTP protocol sessions more visible in your log by increasing your smtpd_tls_loglevel from its zero default. I strongly recommend to not exceed smtpd_tls_loglevel=2, higher values produce excessive logs and reveal connection details best not persisted.

You could make the fact that postfix silently disregarded some keywords more silent by adding the special silent-discard to your smtpd_discard_*_keywords parameter. I strongly recommend to not do that, and instead add comment and/or log parser configuration help future admins (or other readers of that log message) understand your justification for configuring your server with such non-standard behaviour.

user1801810 avatar
cn flag
That is exactly it. Once TLS loglevel was bumped up I see a number of TLS log entries in between the two entries indicating keyword discard. The reset after `STARTTLS` escaped my mind. This all makes sense now. Thanks.
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.