dnsdist: Add support for structured logging

[rgacogne]

Short description

This PR implements structured logging support for DNSdist. A small amount of code is duplicated from the recursor, I tried to refactor it but the result was ugly because some parts are really tied to the recursor.

Checklist

I have:

• read the CONTRIBUTING.md document
• read and accepted the Developer Certificate of Origin document, including the AI Policy, and added a "Signed-off-by" to my commits
• compiled this code
• tested this code
• included documentation (including possible behaviour changes)
• documented the code
• added or modified regression test(s)
• added or modified unit test(s)

[coveralls]

Pull Request Test Coverage Report for Build 21136026407

Warning: This coverage report may be inaccurate.

This pull request's base commit is no longer the HEAD commit of its target branch. This means it includes changes from outside the original pull request, including, potentially, unrelated coverage changes.

• For more information on this, see Tracking coverage changes with pull request builds.
• To avoid this issue with future PRs, see these Recommended CI Configurations.
• For a quick fix, rebase this PR at GitHub. Your next report should be accurate.

Details

• 523 of 1771 (29.53%) changed or added relevant lines in 54 files are covered.
• 10845 unchanged lines in 109 files lost coverage.
• Overall coverage decreased (-0.6%) to 72.722%

---

Changes Missing Coverage	Covered Lines	Changed/Added Lines	%
pdns/dnsdistdist/dnsdist-tcp.hh	1	2	50.0%
pdns/dnsdistdist/dnsdist-console.cc	19	21	90.48%
pdns/dnsdistdist/dnsdist-lua-bindings-packetcache.cc	0	2	0.0%
pdns/dnsdistdist/dnsdist-lua-hooks.cc	0	2	0.0%
pdns/dnsdistdist/dnsdist-lua-network.cc	4	6	66.67%
pdns/dnsdistdist/dnsdist-lua-rules.cc	0	2	0.0%
pdns/dnsdistdist/dnsdist-protobuf.cc	0	2	0.0%
pdns/dnsdistdist/test-dnsdistnghttp2-in_cc.cc	0	2	0.0%
pdns/remote_logger.cc	0	2	0.0%
pdns/dnsdistdist/dnsdist-doh-common.hh	0	3	0.0%

Files with Coverage Reduction	New Missed Lines	%
pdns/dnsdistdist/dolog.cc	1	0.0%
pdns/protozero-trace.hh	1	68.37%
pdns/dnsdistdist/dnsdist-console.cc	1	53.09%
pdns/dnsdistdist/dnsdist-lua-hooks.cc	1	93.59%
pdns/dnsdistdist/dnsdist-protobuf.cc	1	76.17%
pdns/burtle.hh	2	98.19%
pdns/channel.hh	2	54.92%
pdns/dns.cc	2	88.29%
pdns/dnsdistdist/dnsdist-dnsquestion.cc	2	40.79%
pdns/dnsdistdist/dnsdist-lua-bindings-kvs.cc	2	48.0%

Totals
Change from base Build 21131045147:	-0.6%
Covered Lines:	128561
Relevant Lines:	164838

---

💛 - Coveralls

[rgacogne]

Rebased on current master to fix a conflict with #16576.

[rgacogne]

I'll have a look at #16693 to see how we can prevent or minimize conflicts, I'm not too worried.

[rgacogne]

I looked at the possible conflicts with #16693 and edited the first commit of my branch to move logging.cc in pdns/ as is done in the other branch to limit the possible issues. There will be some work to do to merge the changes to logging.hh once one branch is merged, but that doesn't seem very hard to do, regardless of which branch is merged to master first.

[miodvallat]

Note that in the auth PR, the plumbing work consists only of moving recursor-specific bits to the common place; but there is still some code duplication until things settle.

[rgacogne]

Rebased on current master to fix conflicts.

[omoerbeek]

Observation: the subsystem key is not always filled in.

msg="Adding TCP worker thread to handle TCP connections from clients" level="0" prio="Info" ts="1768484074.208"
msg="Adding outgoing DoH worker thread" level="0" prio="Info" ts="1768484074.208"

With rec I always try to make sure that the subsystem key is present.

[rgacogne]

Right, this is unexpected since I documented that key to be always present in dnsdist as well. I'm thinking of adding a mandatory const std::string_view& subsystem parameter to getTopLogger() so that we cannot forget, do you think it would make sense?

[omoerbeek]

Right, this is unexpected since I documented that key to be always present in dnsdist as well. I'm thinking of adding a mandatory const std::string_view& subsystem parameter to getTopLogger() so that we cannot forget, do you think it would make sense?

Yes, I think that would work. In rec I make sure that I never use g_slog directly and create a logger with withName(). But something that can be enforced by the compiler is better.

[miodvallat]

Well, if you use g_slog directly without a withName() alteration, you can only use error() but not info(), which limits your capabilities enough to make you remember to not use a straight g_slog unless there is no other way.

[omoerbeek]

Well, if you use g_slog directly without a withName() alteration, you can only use error() but not info(), which limits your capabilities enough to make you remember to not use a straight g_slog unless there is no other way.

Hmm this diff compiles and runes here:

diff --git a/pdns/recursordist/rec-main.cc b/pdns/recursordist/rec-main.cc
index 3b4851c2d..13d71a912 100644
--- a/pdns/recursordist/rec-main.cc
+++ b/pdns/recursordist/rec-main.cc
@@ -3159,6 +3159,9 @@ int main(int argc, char** argv)
 
     ::arg().setSLog(startupLog);
 
+    g_slog->error(99, "bla");
+    g_slog->info(Logr::Warning, "bla");
+
     string yamlconfigname;
     pdns::rust::settings::rec::Recursorsettings settings;
     pdns::settings::rec::YamlSettingsStatus yamlstatus{};

[miodvallat]

Oh then it's info with the use of multiple Logging::Loggable values perhaps.

[omoerbeek]

Oh then it's info with the use of multiple Logging::Loggable values perhaps.

Both these lines error, so no difference bewteen info and error

    g_slog->error(99, "bla", "k", Logging::Loggable("v"));
    g_slog->info(Logr::Warning, "bla", "k", Logging::Loggable("v"));

[rgacogne]

Right, this is unexpected since I documented that key to be always present in dnsdist as well. I'm thinking of adding a mandatory const std::string_view& subsystem parameter to getTopLogger() so that we cannot forget, do you think it would make sense?

Yes, I think that would work. In rec I make sure that I never use g_slog directly and create a logger with withName(). But something that can be enforced by the compiler is better.

Done.

[pieterlexis]

I like it. But startup is a bit inconsistent. With this config, I get one line of un-structured log and one line of wrongly structured log (wrong backend) before structured logging actually does the right thing:

setStructuredLogging(true, { backend = "json" })
newServer({ address = "8.8.8.8" })

dnsdist 0.0.33893.0.ddiststructuredlogging.g498215c5ae.dirty comes with ABSOLUTELY NO WARRANTY. This is free software, and you are welcome to redistribute it according to the terms of the GPL version 2
msg="Added downstream server" subsystem="configuration" level="0" prio="Info" ts="1768574581.850" backend.address="8.8.8.8:53" lua.function="newServer"
{"frontend.address": "127.0.0.1:5300", "level": "0", "msg": "Raised send buffer size", "network.send_buffer_size": "4194304", "priority": "6", "subsystem": "setup", "ts": "1768574581.850"}

Perhaps we should delay/buffer all logging until config has been parsed. When that was successful, log everything in the right format. If parsing was not successful, just use the default logging settings for the buffered messages.

[rgacogne]

I like it. But startup is a bit inconsistent. With this config, I get one line of un-structured log and one line of wrongly structured log (wrong backend) before structured logging actually does the right thing:

You can use --structured-logging and --structured-logging-backend to prevent that.

Perhaps we should delay/buffer all logging until config has been parsed. When that was successful, log everything in the right format. If parsing was not successful, just use the default logging settings for the buffered messages.

What bothers me about that idea is that if we crash without reaching the "successful" part we get nothing.

[pieterlexis]

That could be a problem indeed. Let's keep it like this and perhaps document that folks should use the command line switches if they need proper logging from the moment of startup.

[pieterlexis]

One nit, but I can live with that. Merge it!

[pieterlexis]

ship it