jbwli...@hilltopgroup.com:
> Hi everyone,
>
> I'm running postfix 3.2.3 on FreeBSD, with a separate submission service
> receiving connections via haproxy and using the
> smtpd_upstream_proxy_protocol=haproxy flag. When haproxy performs its
> checks every 30 seconds, I get the following in my log (I've made it
> more verbose as I'm looking for the problem):
I have deleted all the verbose logging because it makes the problem
harder to debug.
> Jun 21 17:00:08 mail_20170805 postfix-submissionproxy/smtpd[15167]:
> connection established
> Jun 21 17:00:08 mail_20170805 postfix-submissionproxy/smtpd[15167]:
> smtp_get: EOF
> Jun 21 17:00:08 mail_20170805 postfix-submissionproxy/smtpd[15167]:
> warning: haproxy read: unexpected EOF
While reading the HaProxy handshake message, the smtp_get() function
encountered an 'end of input' condition, as if the connection was
closed before smtp_get() could read a complete handshake message.
The HaProxy handshake reader then sets the client info to "unknown"
and sets the SMTPD_FLAG_HANGUP flag. The SMTP server logs the
connection:
> Jun 21 17:00:08 mail_20170805 postfix-submissionproxy/smtpd[15167]:
> connect from unknown[unknown]
The SMTP server skips the command-reading loop because SMTPD_FLAG_HANGUP
is set. Unfortunately it also skips the code that resets the command
counters.
> Jun 21 17:00:08 mail_20170805 postfix-submissionproxy/smtpd[15167]:
> disconnect from unknown[unknown] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1
> data=1 quit=1 commands=8
These are counts from an earlier connection to the same SMTP
server process.
The patch below should work for all Postfix versions that log command
counts. It moves the code that resets the counts into the function
that reports the counts.
Wietse
diff --exclude=man --exclude=html --exclude=README_FILES --exclude=INSTALL
--exclude=.indent.pro --exclude=Makefile.in -r -bur
/var/tmp/postfix-3.5-20190615/src/smtpd/smtpd.c src/smtpd/smtpd.c
--- /var/tmp/postfix-3.5-20190615/src/smtpd/smtpd.c 2019-06-15
20:10:10.000000000 -0400
+++ src/smtpd/smtpd.c 2019-06-21 19:39:49.000000000 -0400
@@ -5422,15 +5422,6 @@
case 0:
/*
- * Reset the per-command counters.
- */
- for (cmdp = smtpd_cmd_table; /* see below */ ; cmdp++) {
- cmdp->success_count = cmdp->total_count = 0;
- if (cmdp->name == 0)
- break;
- }
-
- /*
* In TLS wrapper mode, turn on TLS using code that is shared with
* the STARTTLS command. This code does not return when the handshake
* fails.
@@ -5829,6 +5820,15 @@
}
/*
+ * Reset the per-command counters.
+ */
+ for (cmdp = smtpd_cmd_table; /* see below */ ; cmdp++) {
+ cmdp->success_count = cmdp->total_count = 0;
+ if (cmdp->name == 0)
+ break;
+ }
+
+ /*
* Log total numbers, so that logfile analyzers will see something even
* if the above loop produced no output. When no commands were received
* log "0/0" to simplify the identification of abnormal sessions: any
