From dda69168ead4bb44f5a23949a04ee2069b7d4ef0 Mon Sep 17 00:00:00 2001 From: Mark Andrews Date: Thu, 2 Oct 2014 09:40:11 +1000 Subject: [PATCH] 3965. [func] Log outgoing packets and improve packet logging to support logging the remote address. [RT #36624] --- CHANGES | 3 ++ lib/dns/include/dns/message.h | 29 +++++++++++++++-- lib/dns/message.c | 56 ++++++++++++++++++++++++++++++-- lib/dns/resolver.c | 61 ++++++++++++++++++----------------- lib/dns/xfrin.c | 9 +++--- 5 files changed, 119 insertions(+), 39 deletions(-) diff --git a/CHANGES b/CHANGES index cdec5f95b9..e421635371 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,6 @@ +3965. [func] Log outgoing packets and improve packet logging to + support logging the remote address. [RT #36624] + 3964. [func] nsupdate now performs check-names processing. [RT #36266] diff --git a/lib/dns/include/dns/message.h b/lib/dns/include/dns/message.h index 183ecec755..db85b668e1 100644 --- a/lib/dns/include/dns/message.h +++ b/lib/dns/include/dns/message.h @@ -1372,14 +1372,39 @@ dns_message_logpacket(dns_message_t *message, const char *description, isc_logcategory_t *category, isc_logmodule_t *module, int level, isc_mem_t *mctx); void +dns_message_logpacket2(dns_message_t *message, + const char *description, isc_sockaddr_t *address, + isc_logcategory_t *category, isc_logmodule_t *module, + int level, isc_mem_t *mctx); +void dns_message_logfmtpacket(dns_message_t *message, const char *description, isc_logcategory_t *category, isc_logmodule_t *module, const dns_master_style_t *style, int level, isc_mem_t *mctx); +void +dns_message_logfmtpacket2(dns_message_t *message, + const char *description, isc_sockaddr_t *address, + isc_logcategory_t *category, isc_logmodule_t *module, + const dns_master_style_t *style, int level, + isc_mem_t *mctx); /*%< * Log 'message' at the specified logging parameters. - * 'description' will be emitted at the start of the message and will - * normally end with a newline. + * + * For dns_message_logpacket and dns_message_logfmtpacket expect the + * 'description' to end in a newline. + * + * For dns_message_logpacket2 and dns_message_logfmtpacket2 + * 'description' will be emitted at the start of the message followed + * by the formatted address and a newline. + * + * Requires: + * \li message be a valid. + * \li description to be non NULL. + * \li address to be non NULL. + * \li category to be valid. + * \li module to be valid. + * \li style to be valid. + * \li mctx to be a valid. */ isc_result_t diff --git a/lib/dns/message.c b/lib/dns/message.c index 06b9068dd4..d1c73efe98 100644 --- a/lib/dns/message.c +++ b/lib/dns/message.c @@ -192,6 +192,12 @@ msgblock_reset(dns_msgblock_t *); static inline void msgblock_free(isc_mem_t *, dns_msgblock_t *, unsigned int); +static void +logfmtpacket(dns_message_t *message, const char *description, + isc_sockaddr_t *address, isc_logcategory_t *category, + isc_logmodule_t *module, const dns_master_style_t *style, + int level, isc_mem_t *mctx); + /* * Allocate a new dns_msgblock_t, and return a pointer to it. If no memory * is free, return NULL. @@ -3562,8 +3568,20 @@ dns_message_logpacket(dns_message_t *message, const char *description, isc_logcategory_t *category, isc_logmodule_t *module, int level, isc_mem_t *mctx) { - dns_message_logfmtpacket(message, description, category, module, - &dns_master_style_debug, level, mctx); + logfmtpacket(message, description, NULL, category, module, + &dns_master_style_debug, level, mctx); +} + +void +dns_message_logpacket2(dns_message_t *message, + const char *description, isc_sockaddr_t *address, + isc_logcategory_t *category, isc_logmodule_t *module, + int level, isc_mem_t *mctx) +{ + REQUIRE(address != NULL); + + logfmtpacket(message, description, address, category, module, + &dns_master_style_debug, level, mctx); } void @@ -3572,6 +3590,32 @@ dns_message_logfmtpacket(dns_message_t *message, const char *description, const dns_master_style_t *style, int level, isc_mem_t *mctx) { + logfmtpacket(message, description, NULL, category, module, style, + level, mctx); +} + +void +dns_message_logfmtpacket2(dns_message_t *message, + const char *description, isc_sockaddr_t *address, + isc_logcategory_t *category, isc_logmodule_t *module, + const dns_master_style_t *style, int level, + isc_mem_t *mctx) +{ + REQUIRE(address != NULL); + + logfmtpacket(message, description, address, category, module, style, + level, mctx); +} + +static void +logfmtpacket(dns_message_t *message, const char *description, + isc_sockaddr_t *address, isc_logcategory_t *category, + isc_logmodule_t *module, const dns_master_style_t *style, + int level, isc_mem_t *mctx) +{ + char addrbuf[ISC_SOCKADDR_FORMATSIZE] = { 0 }; + const char *newline = "\n"; + const char *space = " "; isc_buffer_t buffer; char *buf = NULL; int len = 1024; @@ -3585,6 +3629,11 @@ dns_message_logfmtpacket(dns_message_t *message, const char *description, * to appear in the log after each message. */ + if (address != NULL) + isc_sockaddr_format(address, addrbuf, sizeof(addrbuf)); + else + newline = space = ""; + do { buf = isc_mem_get(mctx, len); if (buf == NULL) @@ -3596,7 +3645,8 @@ dns_message_logfmtpacket(dns_message_t *message, const char *description, len += 1024; } else if (result == ISC_R_SUCCESS) isc_log_write(dns_lctx, category, module, level, - "%s%.*s", description, + "%s%s%s%s%.*s", description, space, + addrbuf, newline, (int)isc_buffer_usedlength(&buffer), buf); } while (result == ISC_R_NOSPACE); diff --git a/lib/dns/resolver.c b/lib/dns/resolver.c index 4e869d73ef..7dfc2c6673 100644 --- a/lib/dns/resolver.c +++ b/lib/dns/resolver.c @@ -2253,6 +2253,17 @@ resquery_send(resquery_t *query) { isc_buffer_add(&tcpbuffer, r.length); } + /* + * Log the outgoing packet. + */ + dns_message_logfmtpacket2(fctx->qmessage, "sending packet to", + &query->addrinfo->sockaddr, + DNS_LOGCATEGORY_RESOLVER, + DNS_LOGMODULE_PACKETS, + &dns_master_style_comment, + ISC_LOG_DEBUG(11), + fctx->res->mctx); + /* * We're now done with the query message. */ @@ -7388,12 +7399,13 @@ resquery_response(isc_task_t *task, isc_event_t *event) { /* * Log the incoming packet. */ - dns_message_logfmtpacket(message, "received packet:\n", - DNS_LOGCATEGORY_RESOLVER, - DNS_LOGMODULE_PACKETS, - &dns_master_style_comment, - ISC_LOG_DEBUG(10), - fctx->res->mctx); + dns_message_logfmtpacket2(message, "received packet from", + &query->addrinfo->sockaddr, + DNS_LOGCATEGORY_RESOLVER, + DNS_LOGMODULE_PACKETS, + &dns_master_style_comment, + ISC_LOG_DEBUG(10), + fctx->res->mctx); /* * Process receive opt record. */ @@ -7449,18 +7461,13 @@ resquery_response(isc_task_t *task, isc_event_t *event) { message->rcode == dns_rcode_refused || message->rcode == dns_rcode_yxdomain) && bad_edns(fctx, &query->addrinfo->sockaddr)) { - if (isc_log_wouldlog(dns_lctx, ISC_LOG_DEBUG(3))) { - char buf[4096], addrbuf[ISC_SOCKADDR_FORMATSIZE]; - isc_sockaddr_format(&query->addrinfo->sockaddr, - addrbuf, sizeof(addrbuf)); - snprintf(buf, sizeof(buf), - "received packet from %s (bad edns):\n", - addrbuf); - dns_message_logpacket(message, buf, - DNS_LOGCATEGORY_RESOLVER, - DNS_LOGMODULE_RESOLVER, - ISC_LOG_DEBUG(3), fctx->res->mctx); - } + dns_message_logpacket2(message, + "received packet (bad edns) from", + &query->addrinfo->sockaddr, + DNS_LOGCATEGORY_RESOLVER, + DNS_LOGMODULE_RESOLVER, + ISC_LOG_DEBUG(3), + fctx->res->mctx); dns_adb_changeflags(fctx->adb, query->addrinfo, DNS_FETCHOPT_NOEDNS0, DNS_FETCHOPT_NOEDNS0); @@ -7480,18 +7487,12 @@ resquery_response(isc_task_t *task, isc_event_t *event) { * should be safe to do for any rcode we limit it to NOERROR * and NXDOMAIN. */ - if (isc_log_wouldlog(dns_lctx, ISC_LOG_DEBUG(3))) { - char buf[4096], addrbuf[ISC_SOCKADDR_FORMATSIZE]; - isc_sockaddr_format(&query->addrinfo->sockaddr, - addrbuf, sizeof(addrbuf)); - snprintf(buf, sizeof(buf), - "received packet from %s (no opt):\n", - addrbuf); - dns_message_logpacket(message, buf, - DNS_LOGCATEGORY_RESOLVER, - DNS_LOGMODULE_RESOLVER, - ISC_LOG_DEBUG(3), fctx->res->mctx); - } + dns_message_logpacket2(message, "received packet (no opt) from", + &query->addrinfo->sockaddr, + DNS_LOGCATEGORY_RESOLVER, + DNS_LOGMODULE_RESOLVER, + ISC_LOG_DEBUG(3), + fctx->res->mctx); dns_adb_changeflags(fctx->adb, query->addrinfo, DNS_FETCHOPT_NOEDNS0, DNS_FETCHOPT_NOEDNS0); diff --git a/lib/dns/xfrin.c b/lib/dns/xfrin.c index 744f87802c..7bd704ef19 100644 --- a/lib/dns/xfrin.c +++ b/lib/dns/xfrin.c @@ -1234,10 +1234,11 @@ xfrin_recv_done(isc_task_t *task, isc_event_t *ev) { DNS_MESSAGEPARSE_PRESERVEORDER); if (result == ISC_R_SUCCESS) - dns_message_logpacket(msg, "received message:\n", - DNS_LOGCATEGORY_XFER_IN, - DNS_LOGMODULE_XFER_IN, - ISC_LOG_DEBUG(10), xfr->mctx); + dns_message_logpacket2(msg, "received message from", + &tcpmsg->address, + DNS_LOGCATEGORY_XFER_IN, + DNS_LOGMODULE_XFER_IN, + ISC_LOG_DEBUG(10), xfr->mctx); else xfrin_log(xfr, ISC_LOG_DEBUG(10), "dns_message_parse: %s", dns_result_totext(result));