diff options
37 files changed, 67 insertions, 52 deletions
diff --git a/.luacheckrc b/.luacheckrc index 6248c009..0134706e 100644 --- a/.luacheckrc +++ b/.luacheckrc @@ -18,7 +18,6 @@ new_read_globals = { 'todname', 'tojson', 'user', - 'verbose', 'worker', 'kluautil_list_dir', -- Sandbox declarations diff --git a/ci/respdiff/kresd.config b/ci/respdiff/kresd.config index be5c4582..0539cec7 100644 --- a/ci/respdiff/kresd.config +++ b/ci/respdiff/kresd.config @@ -23,4 +23,4 @@ modules = { local _, up_bs = net.bufsize() net.bufsize(4096, up_bs) -verbose(true) +set_log_level('debug') diff --git a/daemon/cache.test/clear.test.lua b/daemon/cache.test/clear.test.lua index 8185ae52..c2da41cf 100644 --- a/daemon/cache.test/clear.test.lua +++ b/daemon/cache.test/clear.test.lua @@ -15,7 +15,7 @@ end policy.add(policy.suffix(policy.PASS, {todname('test.')})) cache.size = 2*MB --- verbose(true) +-- set_log_level('debug') -- Self-checks on globals assert(help() ~= nil) diff --git a/daemon/cache.test/insert_ns.test.integr/kresd_config.j2 b/daemon/cache.test/insert_ns.test.integr/kresd_config.j2 index 6da4f4fc..11e13c9c 100644 --- a/daemon/cache.test/insert_ns.test.integr/kresd_config.j2 +++ b/daemon/cache.test/insert_ns.test.integr/kresd_config.j2 @@ -48,7 +48,7 @@ if detect_time_skew then end _hint_root_file('hints') -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/daemon/engine.c b/daemon/engine.c index 4d8cad7c..889d886f 100644 --- a/daemon/engine.c +++ b/daemon/engine.c @@ -74,7 +74,6 @@ static int l_help(lua_State *L) "hostname()\n hostname\n" "package_version()\n return package version\n" "user(name[, group])\n change process user (and group)\n" - "verbose(true|false)\n toggle verbose mode\n" "set_log_level\n logging level (crit, err, warning, notice, info or debug)\n" "option(opt[, new_val])\n get/set server option\n" "mode(strict|normal|permissive)\n set resolver strictness level\n" diff --git a/daemon/main.c b/daemon/main.c index dd14692d..7e1112d2 100644 --- a/daemon/main.c +++ b/daemon/main.c @@ -130,7 +130,7 @@ static void help(int argc, char *argv[]) " -c, --config=[path] Config file path (relative to [rundir]) (default: config).\n" " -n, --noninteractive Don't start the read-eval-print loop for stdin+stdout.\n" " -q, --quiet No command prompt in interactive mode.\n" - " -v, --verbose Run in verbose mode.\n" + " -v, --verbose Increase logging to debug level.\n" " -V, --version Print version of the server.\n" " -h, --help Print help and usage.\n" "Options:\n" diff --git a/doc/config-logging-monitoring.rst b/doc/config-logging-monitoring.rst index afddb8be..6250a4fe 100644 --- a/doc/config-logging-monitoring.rst +++ b/doc/config-logging-monitoring.rst @@ -14,8 +14,7 @@ in ``syslog.h``. It is possible change logging level using Logging level ``notice`` is set after start by default, so logs from Knot Resolver should contain only couple lines a day. -For debugging purposes it is possible to enable very verbose logging using -:func:`verbose` function. +For debugging purposes it is possible to use the very verbose ``debug`` level. In addition to levels, logging is also divided into the :ref:`groups <config_log_groups>`. All groups @@ -33,6 +32,9 @@ set by :func:`set_log_level`. .. py:function:: verbose([true | false]) + .. deprecated:: 5.4.0 + Use :func:`set_log_level` instead. + :param: ``true`` enable ``debug`` level, ``false`` switch to default level (``notice``). :return: boolean ``true`` when ``debug`` level is enabled. diff --git a/doc/config-overview.rst b/doc/config-overview.rst index 8613f9e4..3d0f3c69 100644 --- a/doc/config-overview.rst +++ b/doc/config-overview.rst @@ -62,18 +62,31 @@ The **interactive prompt** is denoted by ``>``, so all examples starting with `` > -- this is a comment entered into interactive prompt > -- comments have no effect here > -- the next line shows a command entered interactivelly and its output - > verbose() - false - > -- the previous line without > character is output from verbose() command + > get_log_level() + 'notice' + > -- the previous line without > character is output from get_log_level() command Following example demontrates how to interactivelly list all currently loaded modules, and includes multi-line output: .. code-block:: lua > modules.list() - [1] => iterate - [2] => validate - [3] => cache + { + 'iterate', + 'validate', + 'cache', + 'ta_update', + 'ta_signal_query', + 'policy', + 'priming', + 'detect_time_skew', + 'detect_time_jump', + 'ta_sentinel', + 'edns_keepalive', + 'refuse_nord', + 'watchdog', + } + Before we dive into configuring features, let us explain modularization basics. diff --git a/doc/kresd.8.in b/doc/kresd.8.in index 71eb3013..e2e44715 100644 --- a/doc/kresd.8.in +++ b/doc/kresd.8.in @@ -108,8 +108,7 @@ Daemon will refrain from entering into read-eval-print loop for stdin+stdout. Daemon will refrain from printing the command prompt. .TP .B \-v\fR, \fB\-\-verbose -Increase verbosity. If given multiple times, more information is logged. -This is in addition to the verbosity (if any) from the config file. +Increase logging to debug level. .TP .B \-h Show short commandline option help. diff --git a/etc/config/config.docker b/etc/config/config.docker index 4805ae32..bfededb5 100644 --- a/etc/config/config.docker +++ b/etc/config/config.docker @@ -36,7 +36,7 @@ function interactive_mode() .. '8453 -> web interface\n' .. '\n' .. 'For verbose logging enter following command to prompt below:\n' - .. 'verbose(true)\n') + .. 'set_log_level("debug")\n') end print_help() end @@ -62,7 +62,7 @@ function debug_mode(qname, qtype) -- execute query right after start up and exit when the query is finished event.after(0, function() -- ultra verbose log - verbose(true) + set_log_level('debug') policy.add(policy.all(policy.DEBUG_ALWAYS)) log_debug(ffi.C.LOG_GRP_RESOLVER, 'starting DNS query for %s %s', qname, kres.tostring.type[qtype]) local starttime = cqueues.monotime() diff --git a/lib/cache/overflow.test.integr/kresd_config.j2 b/lib/cache/overflow.test.integr/kresd_config.j2 index 87dbd69a..6279bb56 100644 --- a/lib/cache/overflow.test.integr/kresd_config.j2 +++ b/lib/cache/overflow.test.integr/kresd_config.j2 @@ -29,7 +29,7 @@ if detect_time_skew then modules.unload('detect_time_skew') end -verbose(true) +set_log_level('debug') policy.add(policy.all(policy.DEBUG_ALWAYS)) cache.open(1*MB) diff --git a/lib/cache/test.integr/kresd_config.j2 b/lib/cache/test.integr/kresd_config.j2 index 7c3724bd..b1ae409e 100644 --- a/lib/cache/test.integr/kresd_config.j2 +++ b/lib/cache/test.integr/kresd_config.j2 @@ -26,7 +26,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') policy.add(policy.all(policy.DEBUG_ALWAYS)) {% endraw %} diff --git a/lib/layer/test.integr/kresd_config.j2 b/lib/layer/test.integr/kresd_config.j2 index 57c8542e..3bcd645b 100644 --- a/lib/layer/test.integr/kresd_config.j2 +++ b/lib/layer/test.integr/kresd_config.j2 @@ -63,7 +63,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') policy.add(policy.all(policy.DEBUG_ALWAYS)) {% endraw %} diff --git a/lib/layer/validate.test.integr/kresd_config.j2 b/lib/layer/validate.test.integr/kresd_config.j2 index ba6767f5..47aaee1d 100644 --- a/lib/layer/validate.test.integr/kresd_config.j2 +++ b/lib/layer/validate.test.integr/kresd_config.j2 @@ -27,7 +27,7 @@ if detect_time_skew then end cache.size = 2*MB -verbose(true) +set_log_level('debug') policy.add(policy.all(policy.DEBUG_ALWAYS)) policy.add(policy.all(policy.FORWARD('8.8.8.8'))) {% endraw %} diff --git a/lib/rplan.h b/lib/rplan.h index a0f8f552..5120521d 100644 --- a/lib/rplan.h +++ b/lib/rplan.h @@ -41,7 +41,7 @@ struct kr_qflags { bool BADCOOKIE_AGAIN : 1;/**< Query again because bad cookie returned. */ bool CNAME : 1; /**< Query response contains CNAME in answer section. */ bool REORDER_RR : 1; /**< Reorder cached RRs. */ - bool TRACE : 1; /**< Also log answers if --verbose. */ + bool TRACE : 1; /**< Also log answers on debug level. */ bool NO_0X20 : 1; /**< Disable query case randomization . */ bool DNSSEC_NODS : 1; /**< DS non-existance is proven */ bool DNSSEC_OPTOUT : 1; /**< Closest encloser proof has optout */ diff --git a/modules/bogus_log/test.integr/kresd_config.j2 b/modules/bogus_log/test.integr/kresd_config.j2 index 27c082bf..2b299dab 100644 --- a/modules/bogus_log/test.integr/kresd_config.j2 +++ b/modules/bogus_log/test.integr/kresd_config.j2 @@ -59,7 +59,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/daf/test.integr/kresd_config.j2 b/modules/daf/test.integr/kresd_config.j2 index c8f838d5..60fc0820 100644 --- a/modules/daf/test.integr/kresd_config.j2 +++ b/modules/daf/test.integr/kresd_config.j2 @@ -34,7 +34,7 @@ policy.add(policy.suffix(policy.PASS, {todname('test.')})) _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/http/README.rst b/modules/http/README.rst index 9cfad1f9..f7b52421 100644 --- a/modules/http/README.rst +++ b/modules/http/README.rst @@ -151,7 +151,7 @@ The HTTP module has several built-in services to use. "``/stats``", "Statistics/metrics", "Exported :ref:`metrics <mod-stats-list>` from :ref:`mod-stats` in JSON format." "``/metrics``", "Prometheus metrics", "Exported metrics for Prometheus_." - "``/trace/:name/:type``", "Tracking", ":ref:`Trace resolution <mod-http-trace>` of a DNS query and return the verbose logs." + "``/trace/:name/:type``", "Tracking", ":ref:`Trace resolution <mod-http-trace>` of a DNS query and return its debug-level logs." "``/doh``", "Legacy DNS-over-HTTPS", ":rfc:`8484` endpoint, see :ref:`mod-http-doh`." "``/dns-query``", "Legacy DNS-over-HTTPS", ":rfc:`8484` endpoint, see :ref:`mod-http-doh`." diff --git a/modules/http/trace.rst b/modules/http/trace.rst index 4fb60a3e..a766bc63 100644 --- a/modules/http/trace.rst +++ b/modules/http/trace.rst @@ -9,7 +9,7 @@ Using query policies -------------------- Query policies :any:`policy.DEBUG_ALWAYS`, :any:`policy.DEBUG_CACHE_MISS` or -:any:`policy.DEBUG_IF` can be used to enable verbose logging for selected +:any:`policy.DEBUG_IF` can be used to enable debug-level logging for selected subdomains or queries matching specific conditions. Please refer to their documentation for usage. @@ -18,7 +18,7 @@ Using HTTP module The :ref:`http module <mod-http>` provides ``/trace`` endpoint which allows to trace various aspects of the request execution. The basic mode allows you to resolve a query -and trace verbose logs for it (and messages received): +and trace debug-level logs for it (and messages received): .. code-block:: bash diff --git a/modules/policy/README.rst b/modules/policy/README.rst index fce69e5e..b981f3bb 100644 --- a/modules/policy/README.rst +++ b/modules/policy/README.rst @@ -203,7 +203,8 @@ Following actions act on request and then processing continue until first non-ch .. py:attribute:: QTRACE - Pretty-print DNS response packets from authoritative servers into the verbose log for the query and its sub-queries. It's useful for debugging weird DNS servers. Verbose logging must be enabled using :func:`verbose` for this policy to be effective. + Pretty-print DNS response packets from authoritative servers into debug logs for the query and its sub-queries. It's useful for debugging weird DNS servers. + Note that debug-level logs are off by default; see :func:`set_log_level`. .. code-block:: lua @@ -213,8 +214,8 @@ Following actions act on request and then processing continue until first non-ch .. py:attribute:: REQTRACE - Pretty-print DNS requests from clients into the log. - It's useful for debugging weird DNS clients. + Pretty-print DNS requests from clients into the verbose log. It's useful for debugging weird DNS clients. + Debug-level logging must be enabled for this policy to be effective; see :func:`set_log_level`. It makes most sense together with :ref:`mod-view` (enabling per-client) and probably with verbose logging those request (e.g. ``DEBUG_ALWAYS``). @@ -234,15 +235,15 @@ Following actions act on request and then processing continue until first non-ch .. py:function:: DEBUG_IF(test_function) - :param test_function: Function with single argument of type :c:type:`kr_request` which returns ``true`` if verbose logs for a given request should be printed and ``false`` otherwise. + :param test_function: Function with single argument of type :c:type:`kr_request` which returns ``true`` if debug logs for a given request should be generated and ``false`` otherwise. Enable extra verbose logging but print logs only for requests which match condition specified by ``test_function``. This allows to fine-tune which requests should be printed. - .. warning:: Verbose logging has significant performance impact on resolver and might also overload you logging system because one request can easily generate tens of kilobytes of logs. Always use appropriate `Filters`_ to limit number of requests triggering this action to a minimum! + .. warning:: Logging on debug level has significant performance impact on resolver and might also overload you logging system because one request can easily generate tens of kilobytes of logs. Always use appropriate `Filters`_ to limit number of requests triggering this action to a minimum! - .. note:: ``test_function`` is evaluated only when request is finished. As a result verbose logs for all requests must be collected until request is finished because it is not possible to know beforehand how ``test_function`` at the end evaluates given request. When a request is finalized logs are either printed or thrown away. + .. note:: ``test_function`` is evaluated only when request is finished. As a result debug logs for all requests must be collected until request is finished because it is not possible to know beforehand how ``test_function`` at the end evaluates given request. When a request is finalized logs are either printed or thrown away. - Example usage which gathers verbose logs for all requests in subtree ``dnssec-failed.org.`` and prints verbose logs for all requests finished with states different than ``kres.DONE`` (most importantly ``kres.FAIL``, see :c:type:`kr_layer_state`). + Example usage which gathers verbose logs for all requests in subtree ``dnssec-failed.org.`` and prints debug logs for all requests finished with states different than ``kres.DONE`` (most importantly ``kres.FAIL``, see :c:type:`kr_layer_state`). .. code-block:: lua diff --git a/modules/policy/noipv6.test.integr/kresd_config.j2 b/modules/policy/noipv6.test.integr/kresd_config.j2 index 8e8c2636..31e28d7f 100644 --- a/modules/policy/noipv6.test.integr/kresd_config.j2 +++ b/modules/policy/noipv6.test.integr/kresd_config.j2 @@ -28,7 +28,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/policy/noipvx.test.integr/kresd_config.j2 b/modules/policy/noipvx.test.integr/kresd_config.j2 index 771927bc..027331ff 100644 --- a/modules/policy/noipvx.test.integr/kresd_config.j2 +++ b/modules/policy/noipvx.test.integr/kresd_config.j2 @@ -29,7 +29,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/policy/policy.lua b/modules/policy/policy.lua index fbcfeadb..b943dd40 100644 --- a/modules/policy/policy.lua +++ b/modules/policy/policy.lua @@ -685,7 +685,7 @@ local debug_stashlog_cb = ffi.cast('trace_log_f', function (req, msg) end) ffi.gc(debug_stashlog_cb, free_cb) --- buffer verbose logs and print then only if test() returns a truthy value +-- buffer debug logs and print then only if test() returns a truthy value function policy.DEBUG_IF(test) local debug_finish_cb = ffi.cast('trace_callback_f', function (cbreq) jit.off(true, true) -- JIT for (C -> lua)^2 nesting isn't allowed diff --git a/modules/policy/test.integr/kresd_config.j2 b/modules/policy/test.integr/kresd_config.j2 index 25cf0ee8..180d6186 100644 --- a/modules/policy/test.integr/kresd_config.j2 +++ b/modules/policy/test.integr/kresd_config.j2 @@ -27,7 +27,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/prefill/prefill.test/prefill.test.lua b/modules/prefill/prefill.test/prefill.test.lua index 64c41ca8..05dcb2cf 100644 --- a/modules/prefill/prefill.test/prefill.test.lua +++ b/modules/prefill/prefill.test/prefill.test.lua @@ -14,7 +14,7 @@ end policy.add(policy.suffix(policy.PASS, {todname('test.')})) cache.size = 2*MB --- verbose(true) +-- set_log_level('debug') -- Self-checks on globals assert(help() ~= nil) diff --git a/modules/rebinding/test.integr/kresd_config.j2 b/modules/rebinding/test.integr/kresd_config.j2 index 2f268935..cc52bc92 100644 --- a/modules/rebinding/test.integr/kresd_config.j2 +++ b/modules/rebinding/test.integr/kresd_config.j2 @@ -27,7 +27,7 @@ modules.load('rebinding < iterate') _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') net.ipv6 = false {% endraw %} diff --git a/modules/refuse_nord/test.integr/kresd_config.j2 b/modules/refuse_nord/test.integr/kresd_config.j2 index 3ecdf7d0..b7d9ea1b 100644 --- a/modules/refuse_nord/test.integr/kresd_config.j2 +++ b/modules/refuse_nord/test.integr/kresd_config.j2 @@ -25,7 +25,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/renumber/renumber.test.lua b/modules/renumber/renumber.test.lua index c62bd77d..6703a9d9 100644 --- a/modules/renumber/renumber.test.lua +++ b/modules/renumber/renumber.test.lua @@ -73,7 +73,7 @@ policy.add(policy.all(policy.DEBUG_ALWAYS)) policy.add(policy.suffix(policy.PASS, {todname('test.')})) prepare_cache() -verbose(true) +set_log_level('debug') modules.load('renumber < cache') renumber.config({ -- Source subnet, destination subnet diff --git a/modules/serve_stale/test.integr/kresd_config.j2 b/modules/serve_stale/test.integr/kresd_config.j2 index 5e3f55d7..d6191896 100644 --- a/modules/serve_stale/test.integr/kresd_config.j2 +++ b/modules/serve_stale/test.integr/kresd_config.j2 @@ -27,7 +27,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} {% if DO_IP6 == "true" %} diff --git a/modules/stats/test.integr/kresd_config.j2 b/modules/stats/test.integr/kresd_config.j2 index f16993fa..12fc2651 100644 --- a/modules/stats/test.integr/kresd_config.j2 +++ b/modules/stats/test.integr/kresd_config.j2 @@ -83,7 +83,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/ta_update/ta_update.test.integr/kresd_config.j2 b/modules/ta_update/ta_update.test.integr/kresd_config.j2 index 60ad6131..74f5586c 100644 --- a/modules/ta_update/ta_update.test.integr/kresd_config.j2 +++ b/modules/ta_update/ta_update.test.integr/kresd_config.j2 @@ -22,7 +22,7 @@ end policy.add(policy.suffix(policy.PASS, {todname('test.')})) cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} modules.load('hints') diff --git a/modules/ta_update/ta_update.unmanagedkey.test.integr/kresd_config.j2 b/modules/ta_update/ta_update.unmanagedkey.test.integr/kresd_config.j2 index 7ba468fe..378a1679 100644 --- a/modules/ta_update/ta_update.unmanagedkey.test.integr/kresd_config.j2 +++ b/modules/ta_update/ta_update.unmanagedkey.test.integr/kresd_config.j2 @@ -38,7 +38,7 @@ end policy.add(policy.suffix(policy.PASS, {todname('test.')})) cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} modules.load('hints') diff --git a/modules/view/addr.test.integr/kresd_config.j2 b/modules/view/addr.test.integr/kresd_config.j2 index 14edc1a9..2d85b742 100644 --- a/modules/view/addr.test.integr/kresd_config.j2 +++ b/modules/view/addr.test.integr/kresd_config.j2 @@ -31,7 +31,7 @@ end _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/view/tsig.test.integr/kresd_config.j2 b/modules/view/tsig.test.integr/kresd_config.j2 index 6e2aa196..042da2a8 100644 --- a/modules/view/tsig.test.integr/kresd_config.j2 +++ b/modules/view/tsig.test.integr/kresd_config.j2 @@ -33,7 +33,7 @@ trust_anchors.remove('.') _hint_root_file('hints') cache.size = 2*MB -verbose(true) +set_log_level('debug') {% endraw %} net = { '{{SELF_ADDR}}' } diff --git a/modules/watchdog/watchdog.lua b/modules/watchdog/watchdog.lua index 6c361711..00b6f786 100644 --- a/modules/watchdog/watchdog.lua +++ b/modules/watchdog/watchdog.lua @@ -38,7 +38,7 @@ local function check_answer(logbuf) private.ok_callback() return end - log_info(ffi.C.LOG_GRP_WATCHDOG, 'watchdog query returned unexpected answer! query verbose log:') + log_info(ffi.C.LOG_GRP_WATCHDOG, 'watchdog query returned unexpected answer! query log:') log_info(ffi.C.LOG_GRP_WATCHDOG, table.concat(logbuf, '')) if pkt ~= nil then log_info(ffi.C.LOG_GRP_WATCHDOG, 'problematic answer:\n%s', pkt) diff --git a/scripts/kresd-host.lua b/scripts/kresd-host.lua index 6395a88e..1adaef71 100755 --- a/scripts/kresd-host.lua +++ b/scripts/kresd-host.lua @@ -50,7 +50,7 @@ k = 1 while k <= #arg do verbose = true elseif v == '-d' then verbose = true - table.insert(config, 'verbose(true)') + table.insert(config, 'set_log_level("debug")') elseif v == '-4' then table.insert(config, 'net.ipv6 = false') elseif v == '-6' then diff --git a/tests/pytests/templates/kresd.conf.j2 b/tests/pytests/templates/kresd.conf.j2 index 08c73c88..aa9135e4 100644 --- a/tests/pytests/templates/kresd.conf.j2 +++ b/tests/pytests/templates/kresd.conf.j2 @@ -4,7 +4,9 @@ modules = { 'policy > iterate', } -verbose({{ 'true' if kresd.verbose else 'false' }}) +{% if kresd.verbose %} +set_log_level('debug') +{% endif %} {% if kresd.ip %} net.listen('{{ kresd.ip }}', {{ kresd.port }}) |