Dear all,
I have local patch which implements IP/hostname logging for all SMTP operations.
It simplifies log processing for me since I don't have to keep reference
between session ids and IPs/hostnames and check it every time I need to check
who's originating given SMTP transaction.
Does it make sense for anybody else?
--
With best regards,
Pavel Korovin
Index: usr.sbin/smtpd/mta.c
===================================================================
RCS file: /cvs/src/usr.sbin/smtpd/mta.c,v
retrieving revision 1.201
diff -u -p -r1.201 mta.c
--- usr.sbin/smtpd/mta.c 22 May 2016 16:31:21 -0000 1.201
+++ usr.sbin/smtpd/mta.c 22 Aug 2016 19:33:08 -0000
@@ -1610,8 +1610,8 @@ mta_log(const struct mta_envelope *evp,
const char *relay, const char *status)
{
log_info("%016"PRIx64" mta event=delivery evpid=%016"PRIx64" "
- "from=<%s> to=<%s> rcpt=<%s> source=%s "
- "relay=%s delay=%s result=%s stat=%s",
+ "from=<%s> to=<%s> rcpt=<%s> source=\"%s\" "
+ "relay=\"%s\" delay=%s result=\"%s\" stat=\"%s\"",
evp->session,
evp->id,
evp->task->sender,
Index: usr.sbin/smtpd/smtp_session.c
===================================================================
RCS file: /cvs/src/usr.sbin/smtpd/smtp_session.c,v
retrieving revision 1.285
diff -u -p -r1.285 smtp_session.c
--- usr.sbin/smtpd/smtp_session.c 29 Jul 2016 08:53:07 -0000 1.285
+++ usr.sbin/smtpd/smtp_session.c 22 Aug 2016 19:33:08 -0000
@@ -903,9 +903,10 @@ smtp_session_imsg(struct mproc *p, struc
s->tx->msgid);
TAILQ_FOREACH(rcpt, &s->tx->rcpts, entry) {
- log_info("%016"PRIx64" smtp event=message msgid=%08x "
- "from=<%s%s%s> to=<%s%s%s> size=%zu ndest=%zu
proto=%s",
+ log_info("%016"PRIx64" smtp event=message address=%s
host=%s "
+ "msgid=%08x from=<%s%s%s> to=<%s%s%s> size=%zu
ndest=%zu proto=%s",
s->id,
+ ss_to_text(&s->ss), s->hostname,
s->tx->msgid,
s->tx->evp.sender.user,
s->tx->evp.sender.user[0] == '\0' ? "" : "@",
@@ -969,8 +970,9 @@ smtp_session_imsg(struct mproc *p, struc
s = tree_xpop(&wait_ssl_init, resp_ca_cert->reqid);
if (resp_ca_cert->status == CA_FAIL) {
- log_info("%016"PRIx64" smtp event=closed
reason=ca-failure",
- s->id);
+ log_info("%016"PRIx64" smtp event=closed address=%s
host=%s "
+ "reason=ca-failure",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "CA failure");
return;
}
@@ -996,8 +998,8 @@ smtp_session_imsg(struct mproc *p, struc
s->flags |= SF_VERIFIED;
else if (s->listener->flags & F_TLS_VERIFY) {
log_info("%016"PRIx64" smtp "
- "event=closed reason=cert-check-failed",
- s->id);
+ "event=closed address=%s host=%s
reason=cert-check-failed",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "SSL certificate check failed");
return;
}
@@ -1034,8 +1036,8 @@ smtp_filter_response(uint64_t id, int qu
case QUERY_CONNECT:
if (status != FILTER_OK) {
log_info("%016"PRIx64" smtp "
- "event=closed reason=filter-reject",
- s->id);
+ "event=closed address=%s host=%s
reason=filter-reject",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "rejected by filter");
return;
}
@@ -1255,8 +1257,8 @@ smtp_io(struct io *io, int evt)
switch (evt) {
case IO_TLSREADY:
- log_info("%016"PRIx64" smtp event=starttls ciphers=\"%s\"",
- s->id, ssl_to_text(s->io.ssl));
+ log_info("%016"PRIx64" smtp event=starttls address=%s host=%s
ciphers=\"%s\"",
+ s->id, ss_to_text(&s->ss), s->hostname,
ssl_to_text(s->io.ssl));
s->flags |= SF_SECURE;
s->phase = PHASE_INIT;
@@ -1268,8 +1270,8 @@ smtp_io(struct io *io, int evt)
if (s->listener->flags & F_TLS_VERIFY) {
log_info("%016"PRIx64" smtp "
- "event=closed reason=no-client-cert",
- s->id);
+ "event=closed address=%s host=%s
reason=no-client-cert",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "client did not present certificate");
return;
}
@@ -1280,8 +1282,8 @@ smtp_io(struct io *io, int evt)
x = SSL_get_peer_certificate(s->io.ssl);
if (x) {
log_info("%016"PRIx64" smtp "
- "event=client-cert-check result=\"%s\"",
- s->id,
+ "event=client-cert-check address=%s host=%s
result=\"%s\"",
+ s->id, ss_to_text(&s->ss), s->hostname,
(s->flags & SF_VERIFIED) ? "success" : "failure");
X509_free(x);
}
@@ -1357,8 +1359,9 @@ smtp_io(struct io *io, int evt)
case IO_LOWAT:
if (s->state == STATE_QUIT) {
- log_info("%016"PRIx64" smtp event=closed reason=quit",
- s->id);
+ log_info("%016"PRIx64" smtp event=closed address=%s
host=%s "
+ "reason=quit",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "done");
break;
}
@@ -1387,20 +1390,23 @@ smtp_io(struct io *io, int evt)
break;
case IO_TIMEOUT:
- log_info("%016"PRIx64" smtp event=closed reason=timeout",
- s->id);
+ log_info("%016"PRIx64" smtp event=closed address=%s host=%s "
+ "reason=timeout",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "timeout");
break;
case IO_DISCONNECTED:
- log_info("%016"PRIx64" smtp event=closed reason=disconnect",
- s->id);
+ log_info("%016"PRIx64" smtp event=closed address=%s host=%s "
+ "reason=disconnect",
+ s->id, ss_to_text(&s->ss), s->hostname);
smtp_free(s, "disconnected");
break;
case IO_ERROR:
- log_info("%016"PRIx64" smtp event=closed reason=\"io-error:
%s\"",
- s->id, io->error);
+ log_info("%016"PRIx64" smtp event=closed address=%s host=%s "
+ "reason=\"io-error: %s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, io->error);
smtp_free(s, "IO error");
break;
@@ -2224,26 +2230,33 @@ smtp_reply(struct smtp_session *s, char
case '4':
if (s->flags & SF_BADINPUT) {
log_info("%016"PRIx64" smtp "
- "event=bad-input result=\"%.*s\"",
- s->id, n, buf);
+ "event=bad-input address=%s host=%s
result=\"%.*s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, n, buf);
}
else if (s->state == STATE_AUTH_INIT) {
- log_info("smtp-in: Failed command on session %016"PRIx64
- ": \"AUTH PLAIN (...)\" => %.*s", s->id, n, buf);
+ log_info("%016"PRIx64" smtp "
+ "event=failed-command address=%s host=%s "
+ "command=\"AUTH PLAIN (...)\" result=\"%.*s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, n, buf);
}
else if (s->state == STATE_AUTH_USERNAME) {
- log_info("smtp-in: Failed command on session %016"PRIx64
- ": \"AUTH LOGIN (username)\" => %.*s", s->id, n,
buf);
+ log_info("%016"PRIx64" smtp "
+ "event=failed-command address=%s host=%s "
+ "command=\"AUTH LOGIN (username)\" result=\"%.*s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, n, buf);
}
else if (s->state == STATE_AUTH_PASSWORD) {
- log_info("smtp-in: Failed command on session %016"PRIx64
- ": \"AUTH LOGIN (password)\" => %.*s", s->id, n,
buf);
+ log_info("%016"PRIx64" smtp "
+ "event=failed-command address=%s host=%s "
+ "command=\"AUTH LOGIN (password)\" result=\"%.*s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, n, buf);
}
else {
strnvis(tmp, s->cmd, sizeof tmp, VIS_SAFE | VIS_CSTYLE);
log_info("%016"PRIx64" smtp "
- "event=failed-command command=\"%s\"
result=\"%.*s\"",
- s->id, tmp, n, buf);
+ "event=failed-command address=%s host=%s
command=\"%s\" "
+ "result=\"%.*s\"",
+ s->id, ss_to_text(&s->ss), s->hostname, tmp, n,
buf);
}
break;
}
