From: Wietse Venema Date: Fri, 1 Aug 2014 05:00:00 +0000 (-0500) Subject: postfix-2.12-20140801 X-Git-Tag: v3.0.0-RC1~39 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=2b322a12db3c562aeb2e3904bed6b44521adf347;p=thirdparty%2Fpostfix.git postfix-2.12-20140801 --- diff --git a/postfix/HISTORY b/postfix/HISTORY index bbd440f0a..9b28f52bb 100644 --- a/postfix/HISTORY +++ b/postfix/HISTORY @@ -20315,3 +20315,10 @@ Apologies for any names omitted. that was originally part of the RELEASE_NOTES file. Files: proto/SMTPUTF8_README.html, proto/Makefile.in, html/index.html. +20140731 + + Feature: the Postfix SMTP server now logs at the end of + a session how many times each SMTP command was successfully + invoked, followed by the total number of invocations if it + is different. File: smtpd/smtpd.c. + diff --git a/postfix/RELEASE_NOTES b/postfix/RELEASE_NOTES index e8adebce9..c49daae86 100644 --- a/postfix/RELEASE_NOTES +++ b/postfix/RELEASE_NOTES @@ -41,6 +41,37 @@ Maintainers may also benefit from the makedefs documentation (mantools/srctoman - makedefs | nroff -man | less) with information about build options that are not described in the INSTALL instructions. +Major changes with snapshot 20140801 +==================================== + +The Postfix SMTP server now logs at the end of a session how many +times an SMTP command was successfully invoked, followed by the +total number of invocations if it is different. + +This logging will often be enough to diagnose a problem without +verbose logging or network sniffer. + + Normal session, no TLS: + disconnect from name[addr] ehlo=1 mail=1 rcpt=1 data=1 quit=1 + + Normal session. with TLS: + disconnect from name[addr] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 + + All recipients rejected, no ESMTP command pipelining: + disconnect from name[addr] ehlo=1 mail=1 rcpt=0/1 quit=1 + + All recipients rejected, with ESMTP command pipelining: + disconnect from name[addr] ehlo=1 mail=1 rcpt=0/1 data=0/1 rset=1 quit=1 + + Password guessing bot, hangs up without QUIT: + disconnect from name[addr] ehlo=1 auth=0/1 + + Mis-configured client trying to use TLS wrappermode on port 587: + disconnect from name[addr] unknown=0/1 + +Logfile analyzers can trigger on the presence of "/". It indicates +that Postfix rejected at least one command. + Incompatible changes with snapshot 20140714 =========================================== diff --git a/postfix/src/global/mail_version.h b/postfix/src/global/mail_version.h index 596b58ee1..c2a8dc360 100644 --- a/postfix/src/global/mail_version.h +++ b/postfix/src/global/mail_version.h @@ -20,7 +20,7 @@ * Patches change both the patchlevel and the release date. Snapshots have no * patchlevel; they change the release date only. */ -#define MAIL_RELEASE_DATE "20140731" +#define MAIL_RELEASE_DATE "20140801" #define MAIL_VERSION_NUMBER "2.12" #ifdef SNAPSHOT diff --git a/postfix/src/smtpd/smtpd.c b/postfix/src/smtpd/smtpd.c index 8e24768d3..ba9e77682 100644 --- a/postfix/src/smtpd/smtpd.c +++ b/postfix/src/smtpd/smtpd.c @@ -4597,6 +4597,8 @@ typedef struct SMTPD_CMD { char *name; int (*action) (SMTPD_STATE *, int, SMTPD_TOKEN *); int flags; + int success_count; + int total_count; } SMTPD_CMD; #define SMTPD_CMD_FLAG_LIMIT (1<<0) /* limit usage */ @@ -4604,25 +4606,25 @@ typedef struct SMTPD_CMD { #define SMTPD_CMD_FLAG_LAST (1<<2) /* last in PIPELINING command group */ static SMTPD_CMD smtpd_cmd_table[] = { - SMTPD_CMD_HELO, helo_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST, - SMTPD_CMD_EHLO, ehlo_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST, + {SMTPD_CMD_HELO, helo_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST,}, + {SMTPD_CMD_EHLO, ehlo_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST,}, + {SMTPD_CMD_XCLIENT, xclient_cmd,}, + {SMTPD_CMD_XFORWARD, xforward_cmd,}, #ifdef USE_TLS - SMTPD_CMD_STARTTLS, starttls_cmd, SMTPD_CMD_FLAG_PRE_TLS, + {SMTPD_CMD_STARTTLS, starttls_cmd, SMTPD_CMD_FLAG_PRE_TLS,}, #endif #ifdef USE_SASL_AUTH - SMTPD_CMD_AUTH, smtpd_sasl_auth_cmd, 0, + {SMTPD_CMD_AUTH, smtpd_sasl_auth_cmd,}, #endif - SMTPD_CMD_MAIL, mail_cmd, 0, - SMTPD_CMD_RCPT, rcpt_cmd, 0, - SMTPD_CMD_DATA, data_cmd, SMTPD_CMD_FLAG_LAST, - SMTPD_CMD_RSET, rset_cmd, SMTPD_CMD_FLAG_LIMIT, - SMTPD_CMD_NOOP, noop_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST, - SMTPD_CMD_VRFY, vrfy_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_LAST, - SMTPD_CMD_ETRN, etrn_cmd, SMTPD_CMD_FLAG_LIMIT, - SMTPD_CMD_QUIT, quit_cmd, SMTPD_CMD_FLAG_PRE_TLS, - SMTPD_CMD_XCLIENT, xclient_cmd, 0, - SMTPD_CMD_XFORWARD, xforward_cmd, 0, - 0, + {SMTPD_CMD_MAIL, mail_cmd,}, + {SMTPD_CMD_RCPT, rcpt_cmd,}, + {SMTPD_CMD_DATA, data_cmd, SMTPD_CMD_FLAG_LAST,}, + {SMTPD_CMD_RSET, rset_cmd, SMTPD_CMD_FLAG_LIMIT,}, + {SMTPD_CMD_NOOP, noop_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_PRE_TLS | SMTPD_CMD_FLAG_LAST,}, + {SMTPD_CMD_VRFY, vrfy_cmd, SMTPD_CMD_FLAG_LIMIT | SMTPD_CMD_FLAG_LAST,}, + {SMTPD_CMD_ETRN, etrn_cmd, SMTPD_CMD_FLAG_LIMIT,}, + {SMTPD_CMD_QUIT, quit_cmd, SMTPD_CMD_FLAG_PRE_TLS,}, + {0,}, }; static STRING_LIST *smtpd_noop_cmds; @@ -4868,6 +4870,18 @@ static void smtpd_proto(SMTPD_STATE *state) var_smtpd_sasl_opts); #endif + /* + * 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; + } + + /* + * The command read/execute loop. + */ for (;;) { if (state->flags & SMTPD_FLAG_HANGUP) break; @@ -4912,6 +4926,7 @@ static void smtpd_proto(SMTPD_STATE *state) for (cmdp = smtpd_cmd_table; cmdp->name != 0; cmdp++) if (strcasecmp(argv[0].strval, cmdp->name) == 0) break; + cmdp->total_count += 1; /* Ignore smtpd_forbid_cmds lookup errors. Non-critical feature. */ if (cmdp->name == 0) { state->where = SMTPD_CMD_UNKNOWN; @@ -4978,6 +4993,8 @@ static void smtpd_proto(SMTPD_STATE *state) } if (cmdp->action(state, argc, argv) != 0) state->error_count++; + else + cmdp->success_count += 1; if ((cmdp->flags & SMTPD_CMD_FLAG_LIMIT) && state->junk_cmds++ > var_smtpd_junk_cmd_limit) state->error_count++; @@ -5047,6 +5064,28 @@ static void smtpd_proto(SMTPD_STATE *state) milter_disc_event(smtpd_milters); } +/* smtpd_format_cmd_stats - format per-command statistics */ + +static char *smtpd_format_cmd_stats(VSTRING *buf) +{ + SMTPD_CMD *cmdp; + + VSTRING_RESET(buf); + for (cmdp = smtpd_cmd_table; /* see below */ ; cmdp++) { + if (cmdp->total_count > 0) { + vstring_sprintf_append(buf, " %s=%d", + cmdp->name ? cmdp->name : "unknown", + cmdp->success_count); + if (cmdp->success_count != cmdp->total_count) + vstring_sprintf_append(buf, "/%d", cmdp->total_count); + } + if (cmdp->name == 0) + break; + } + return (lowercase(STR(buf))); +} + + /* smtpd_service - service one client */ static void smtpd_service(VSTREAM *stream, char *service, char **argv) @@ -5117,7 +5156,8 @@ static void smtpd_service(VSTREAM *stream, char *service, char **argv) * After the client has gone away, clean up whatever we have set up at * connection time. */ - msg_info("disconnect from %s", state.namaddr); + msg_info("disconnect from %s%s", state.namaddr, + smtpd_format_cmd_stats(state.buffer)); smtpd_state_reset(&state); debug_peer_restore(); }