From 5fad79c92f948b1399603942514ee0a34aad64a3 Mon Sep 17 00:00:00 2001 From: Mark Andrews Date: Wed, 19 Jun 2019 16:20:24 +1000 Subject: [PATCH] Log the rcode returned to for a query Log to the querylog the rcode of a previous query using the identifier 'response:' to diffenciate queries from responses. --- bin/named/config.c | 2 ++ bin/named/control.c | 2 ++ bin/named/include/named/control.h | 1 + bin/named/include/named/server.h | 7 ++++ bin/named/server.c | 55 +++++++++++++++++++++++++++++- bin/rndc/rndc.rst | 11 ++++++ doc/arm/logging-categories.inc.rst | 5 ++- doc/misc/options | 1 + lib/isc/include/isc/log.h | 1 + lib/isc/log.c | 1 + lib/isccfg/namedconf.c | 1 + lib/ns/include/ns/server.h | 1 + lib/ns/query.c | 39 ++++++++++++++++++++- util/check-categories.sh | 4 +-- 14 files changed, 126 insertions(+), 5 deletions(-) diff --git a/bin/named/config.c b/bin/named/config.c index 70dd25942b..94df346db4 100644 --- a/bin/named/config.c +++ b/bin/named/config.c @@ -95,10 +95,12 @@ options {\n\ #endif "\ prefetch 2 9;\n\ +# querylog ;\n\ recursing-file \"named.recursing\";\n\ recursive-clients 1000;\n\ request-nsid false;\n\ resolver-query-timeout 10;\n\ +# responselog ;\n\ rrset-order { order random; };\n\ secroots-file \"named.secroots\";\n\ send-cookie true;\n\ diff --git a/bin/named/control.c b/bin/named/control.c index 7a60bae870..d430d903b0 100644 --- a/bin/named/control.c +++ b/bin/named/control.c @@ -256,6 +256,8 @@ named_control_docommand(isccc_sexpr_t *message, bool readonly, result = named_server_refreshcommand(named_g_server, lex, text); } else if (command_compare(command, NAMED_COMMAND_RELOAD)) { result = named_server_reloadcommand(named_g_server, lex, text); + } else if (command_compare(command, NAMED_COMMAND_RESPONSELOG)) { + result = named_server_toggleresponselog(named_g_server, lex); } else if (command_compare(command, NAMED_COMMAND_RETRANSFER)) { result = named_server_retransfercommand(named_g_server, lex, text); diff --git a/bin/named/include/named/control.h b/bin/named/include/named/control.h index c00900847f..cb3c69c820 100644 --- a/bin/named/include/named/control.h +++ b/bin/named/include/named/control.h @@ -54,6 +54,7 @@ #define NAMED_COMMAND_RECURSING "recursing" #define NAMED_COMMAND_REFRESH "refresh" #define NAMED_COMMAND_RELOAD "reload" +#define NAMED_COMMAND_RESPONSELOG "responselog" #define NAMED_COMMAND_RETRANSFER "retransfer" #define NAMED_COMMAND_SCAN "scan" #define NAMED_COMMAND_SECROOTS "secroots" diff --git a/bin/named/include/named/server.h b/bin/named/include/named/server.h index bfe6a238ce..9bf79da718 100644 --- a/bin/named/include/named/server.h +++ b/bin/named/include/named/server.h @@ -187,6 +187,13 @@ named_server_togglequerylog(named_server_t *server, isc_lex_t *lex); * but can also be used as a toggle for backward comptibility.) */ +isc_result_t +named_server_toggleresponselog(named_server_t *server, isc_lex_t *lex); +/*%< + * Enable/disable logging of responses. (Takes "yes" or "no" argument, + * but can also be used as a toggle for backward comptibility.) + */ + /*% * Save the current NTAs for all views to files. */ diff --git a/bin/named/server.c b/bin/named/server.c index 8341058333..1fd36d01e8 100644 --- a/bin/named/server.c +++ b/bin/named/server.c @@ -9119,6 +9119,13 @@ load_configuration(const char *filename, named_server_t *server, } } } + obj = NULL; + result = named_config_get(maps, "responselog", &obj); + if (result == ISC_R_SUCCESS) { + ns_server_setoption(server->sctx, + NS_SERVER_LOGRESPONSES, + cfg_obj_asboolean(obj)); + } } obj = NULL; @@ -10668,7 +10675,7 @@ named_server_refreshcommand(named_server_t *server, isc_lex_t *lex, isc_result_t named_server_togglequerylog(named_server_t *server, isc_lex_t *lex) { bool prev, value; - char *ptr; + char *ptr = NULL; /* Skip the command name. */ ptr = next_token(lex, NULL); @@ -10705,6 +10712,46 @@ named_server_togglequerylog(named_server_t *server, isc_lex_t *lex) { return (ISC_R_SUCCESS); } +isc_result_t +named_server_toggleresponselog(named_server_t *server, isc_lex_t *lex) { + bool prev, value; + char *ptr = NULL; + + /* Skip the command name. */ + ptr = next_token(lex, NULL); + if (ptr == NULL) { + return (ISC_R_UNEXPECTEDEND); + } + + prev = ns_server_getoption(server->sctx, NS_SERVER_LOGRESPONSES); + + ptr = next_token(lex, NULL); + if (ptr == NULL) { + value = !prev; + } else if (!strcasecmp(ptr, "on") || !strcasecmp(ptr, "yes") || + !strcasecmp(ptr, "enable") || !strcasecmp(ptr, "true")) + { + value = true; + } else if (!strcasecmp(ptr, "off") || !strcasecmp(ptr, "no") || + !strcasecmp(ptr, "disable") || !strcasecmp(ptr, "false")) + { + value = false; + } else { + return (DNS_R_SYNTAX); + } + + if (value == prev) { + return (ISC_R_SUCCESS); + } + + ns_server_setoption(server->sctx, NS_SERVER_LOGRESPONSES, value); + + isc_log_write(NAMED_LOGCATEGORY_GENERAL, NAMED_LOGMODULE_SERVER, + ISC_LOG_INFO, "response logging is now %s", + value ? "on" : "off"); + return (ISC_R_SUCCESS); +} + static isc_result_t listenlist_fromconfig(const cfg_obj_t *listenlist, const cfg_obj_t *config, cfg_aclconfctx_t *actx, isc_mem_t *mctx, uint16_t family, @@ -12087,6 +12134,12 @@ named_server_status(named_server_t *server, isc_buffer_t **text) { : "OFF"); CHECK(putstr(text, line)); + snprintf(line, sizeof(line), "response logging is %s\n", + ns_server_getoption(server->sctx, NS_SERVER_LOGRESPONSES) + ? "ON" + : "OFF"); + CHECK(putstr(text, line)); + snprintf(line, sizeof(line), "recursive clients: %u/%u/%u\n", isc_quota_getused(&server->sctx->recursionquota), isc_quota_getsoft(&server->sctx->recursionquota), diff --git a/bin/rndc/rndc.rst b/bin/rndc/rndc.rst index 55ea4d3147..b59f62e672 100644 --- a/bin/rndc/rndc.rst +++ b/bin/rndc/rndc.rst @@ -458,6 +458,17 @@ Currently supported commands are: .. program:: rndc +.. option:: responselog [on | off] + + This command enables or disables response logging. For backward compatibility, + this command can also be used without an argument to toggle response logging + on and off. + + Unlike query logging, response logging cannot be enabled by explicitly directing + the ``responses`` ``category`` to a ``channel`` in the ``logging`` section + of :iscman:`named.conf`, but it can still be enabled by specifying + ``responselog yes;`` in the ``options`` section of :iscman:`named.conf`. + .. option:: retransfer [-force] zone [class [view]] This command retransfers the given secondary zone from the primary server. diff --git a/doc/arm/logging-categories.inc.rst b/doc/arm/logging-categories.inc.rst index c80c17fe7f..949631c49a 100644 --- a/doc/arm/logging-categories.inc.rst +++ b/doc/arm/logging-categories.inc.rst @@ -56,7 +56,7 @@ NSID options received from upstream servers. ``queries`` - A location where queries should be logged. + The locations where queries should be logged. At startup, specifying the category ``queries`` also enables query logging unless the :any:`querylog` option has been specified. @@ -80,6 +80,9 @@ ``resolver`` DNS resolution, such as the recursive lookups performed on behalf of clients by a caching name server. +``responses`` + The locations where query response summaries should be logged. + ``rpz`` Information about errors in response policy zone files, rewritten responses, and, at the highest ``debug`` levels, mere rewriting attempts. diff --git a/doc/misc/options b/doc/misc/options index 2b281c724c..b3714e4d38 100644 --- a/doc/misc/options +++ b/doc/misc/options @@ -260,6 +260,7 @@ options { resolver-use-dns64 ; response-padding { ; ... } block-size ; response-policy { zone [ add-soa ] [ log ] [ max-policy-ttl ] [ min-update-interval ] [ policy ( cname | disabled | drop | given | no-op | nodata | nxdomain | passthru | tcp-only ) ] [ recursive-only ] [ nsip-enable ] [ nsdname-enable ] [ ede ]; ... } [ add-soa ] [ break-dnssec ] [ max-policy-ttl ] [ min-update-interval ] [ min-ns-dots ] [ nsip-wait-recurse ] [ nsdname-wait-recurse ] [ qname-wait-recurse ] [ recursive-only ] [ nsip-enable ] [ nsdname-enable ] [ dnsrps-enable ] [ dnsrps-options { } ]; + responselog ; reuseport ; root-key-sentinel ; rrset-order { [ class ] [ type ] [ name ] ; ... }; diff --git a/lib/isc/include/isc/log.h b/lib/isc/include/isc/log.h index 579e96e4ff..c7d02cce96 100644 --- a/lib/isc/include/isc/log.h +++ b/lib/isc/include/isc/log.h @@ -146,6 +146,7 @@ enum isc_logcategory { NS_LOGCATEGORY_QUERY_ERRORS, NS_LOGCATEGORY_TAT, NS_LOGCATEGORY_SERVE_STALE, + NS_LOGCATEGORY_RESPONSES, /* cfg categories */ CFG_LOGCATEGORY_CONFIG, /* named categories */ diff --git a/lib/isc/log.c b/lib/isc/log.c index 4073ce4182..53dcb47921 100644 --- a/lib/isc/log.c +++ b/lib/isc/log.c @@ -197,6 +197,7 @@ static const char *categories_description[] = { [NS_LOGCATEGORY_QUERY_ERRORS] = "query-errors", [NS_LOGCATEGORY_TAT] = "trust-anchor-telemetry", [NS_LOGCATEGORY_SERVE_STALE] = "serve-stale", + [NS_LOGCATEGORY_RESPONSES] = "responses", /* cfg categories */ [CFG_LOGCATEGORY_CONFIG] = "config", /* named categories */ diff --git a/lib/isccfg/namedconf.c b/lib/isccfg/namedconf.c index 5d1c2abd4e..9a30bdfd8d 100644 --- a/lib/isccfg/namedconf.c +++ b/lib/isccfg/namedconf.c @@ -1327,6 +1327,7 @@ static cfg_clausedef_t options_clauses[] = { { "recursive-clients", &cfg_type_uint32, 0 }, { "reuseport", &cfg_type_boolean, 0 }, { "reserved-sockets", &cfg_type_uint32, CFG_CLAUSEFLAG_ANCIENT }, + { "responselog", &cfg_type_boolean, 0 }, { "secroots-file", &cfg_type_qstring, 0 }, { "serial-queries", NULL, CFG_CLAUSEFLAG_ANCIENT }, { "serial-query-rate", &cfg_type_uint32, 0 }, diff --git a/lib/ns/include/ns/server.h b/lib/ns/include/ns/server.h index ec6636a0fd..fa21986ca4 100644 --- a/lib/ns/include/ns/server.h +++ b/lib/ns/include/ns/server.h @@ -49,6 +49,7 @@ #define NS_SERVER_TRANSFERINSECS 0x00008000U /*%< -T transferinsecs */ #define NS_SERVER_TRANSFERSLOWLY 0x00010000U /*%< -T transferslowly */ #define NS_SERVER_TRANSFERSTUCK 0x00020000U /*%< -T transferstuck */ +#define NS_SERVER_LOGRESPONSES 0x00040000U /*%< log responses */ /*% * Type for callback function to get hostname. diff --git a/lib/ns/query.c b/lib/ns/query.c index d5c21e0621..ed7d35d73f 100644 --- a/lib/ns/query.c +++ b/lib/ns/query.c @@ -48,6 +48,7 @@ #include #include #include +#include #include #include #include @@ -545,6 +546,30 @@ inc_stats(ns_client_t *client, isc_statscounter_t counter) { } } +static inline void +log_response(ns_client_t *client, dns_rcode_t rcode) { + char namebuf[DNS_NAME_FORMATSIZE]; + char typebuf[DNS_RDATATYPE_FORMATSIZE]; + char classbuf[DNS_RDATACLASS_FORMATSIZE]; + char rcodebuf[20]; + isc_buffer_t b; + int level = ISC_LOG_INFO; + + if (!isc_log_wouldlog(level)) + return; + + dns_name_format(client->query.origqname, namebuf, sizeof(namebuf)); + dns_rdataclass_format(client->message->rdclass, classbuf, + sizeof(classbuf)); + dns_rdatatype_format(client->query.qtype, typebuf, sizeof(typebuf)); + isc_buffer_init(&b, rcodebuf, sizeof(rcodebuf)); + dns_rcode_totext(rcode, &b); + + ns_client_log(client, NS_LOGCATEGORY_QUERIES, NS_LOGMODULE_QUERY, level, + "response: %s %s %s %.*s", namebuf, classbuf, typebuf, + (int)isc_buffer_usedlength(&b), rcodebuf); +} + static void query_send(ns_client_t *client) { isc_statscounter_t counter; @@ -574,6 +599,10 @@ query_send(ns_client_t *client) { counter = ns_statscounter_failure; } + if ((client->manager->sctx->options & NS_SERVER_LOGRESPONSES) != 0) { + log_response(client, client->message->rcode); + } + inc_stats(client, counter); ns_client_send(client); @@ -585,8 +614,10 @@ query_send(ns_client_t *client) { static void query_error(ns_client_t *client, isc_result_t result, int line) { int loglevel = ISC_LOG_DEBUG(3); + dns_rcode_t rcode; - switch (dns_result_torcode(result)) { + rcode = dns_result_torcode(result); + switch (rcode) { case dns_rcode_servfail: loglevel = ISC_LOG_DEBUG(1); inc_stats(client, ns_statscounter_servfail); @@ -605,6 +636,12 @@ query_error(ns_client_t *client, isc_result_t result, int line) { log_queryerror(client, result, line, loglevel); + if (client->query.origqname != NULL && + (client->manager->sctx->options & NS_SERVER_LOGRESPONSES) != 0) + { + log_response(client, rcode); + } + ns_client_error(client, result); if (!client->nodetach) { diff --git a/util/check-categories.sh b/util/check-categories.sh index 2f5909181f..e45dafe33f 100644 --- a/util/check-categories.sh +++ b/util/check-categories.sh @@ -34,7 +34,7 @@ for i in $list1; do fi done if test $ok = no; then - echo "$i missing from documentation." + echo "$i missing from doc/arm/logging-categories.rst." status=1 fi done @@ -46,7 +46,7 @@ for i in $list2; do fi done if test $ok = no; then - echo "$i not in code." + echo "documented logging category '$i' not in code." status=1 fi done