On 08/25/16 15:39, Gilles Chehade wrote: > On Mon, Aug 22, 2016 at 11:10:28PM +0300, Pavel Korovin wrote: >> 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? >> > > Yes, I'll take care of this during the general hackathon next week, thanks ;-) > I like the diff and proper testing is on my todo list for g2k16 as well. Cheers Giovanni
> >> 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; >> } > >