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;
>> }
>
>
