resolved: cache stringified transaction key once per transaction

We end up needing the stringified transaction key in many log messages,
hence let's simplify the logic and cache it inside of the transaction:
generate it the first time we need it, and reuse it afterwards. Free it
when the transaction goes away.

This also updated a couple of log messages to make use of this.

diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c
index f09788b0c67159da650d54b9ef11a66ab1e5dc06..16740d40f4435d9f929482429da4fde94cdb92b9 100644 (file)
--- a/src/resolve/resolved-dns-transaction.c
+++ b/src/resolve/resolved-dns-transaction.c
@@ -80,6 +80,7 @@ DnsTransaction* dns_transaction_free(DnsTransaction *t) {
 
         dns_answer_unref(t->validated_keys);
 
+        free(t->key_string);
         free(t);
         return NULL;
 }
@@ -182,7 +183,9 @@ static void dns_transaction_tentative(DnsTransaction *t, DnsPacket *p) {
 
         in_addr_to_string(p->family, &p->sender, &pretty);
 
-        log_debug("Transaction on scope %s on %s/%s got tentative packet from %s",
+        log_debug("Transaction %" PRIu16 " for <%s> on scope %s on %s/%s got tentative packet from %s.",
+                  t->id,
+                  dns_transaction_key_string(t),
                   dns_protocol_to_string(t->scope->protocol),
                   t->scope->link ? t->scope->link->name : "*",
                   t->scope->family == AF_UNSPEC ? "*" : af_to_name(t->scope->family),
@@ -225,12 +228,15 @@ void dns_transaction_complete(DnsTransaction *t, DnsTransactionState state) {
          * should hence not attempt to access the query or transaction
          * after calling this function. */
 
-        log_debug("Transaction on scope %s on %s/%s now complete with <%s> from %s",
+        log_debug("Transaction %" PRIu16 " for <%s> on scope %s on %s/%s now complete with <%s> from %s (%s).",
+                  t->id,
+                  dns_transaction_key_string(t),
                   dns_protocol_to_string(t->scope->protocol),
                   t->scope->link ? t->scope->link->name : "*",
                   t->scope->family == AF_UNSPEC ? "*" : af_to_name(t->scope->family),
                   dns_transaction_state_to_string(state),
-                  t->answer_source < 0 ? "none" : dns_transaction_source_to_string(t->answer_source));
+                  t->answer_source < 0 ? "none" : dns_transaction_source_to_string(t->answer_source),
+                  t->answer_authenticated ? "authenticated" : "unsigned");
 
         t->state = state;
 
@@ -980,17 +986,12 @@ int dns_transaction_go(DnsTransaction *t) {
         if (r <= 0)
                 return r;
 
-        if (log_get_max_level() >= LOG_DEBUG) {
-                _cleanup_free_ char *ks = NULL;
-
-                (void) dns_resource_key_to_string(t->key, &ks);
-
-                log_debug("Excercising transaction for <%s> on scope %s on %s/%s",
-                          ks ? strstrip(ks) : "???",
-                          dns_protocol_to_string(t->scope->protocol),
-                          t->scope->link ? t->scope->link->name : "*",
-                          t->scope->family == AF_UNSPEC ? "*" : af_to_name(t->scope->family));
-        }
+        log_debug("Excercising transaction %" PRIu16 " for <%s> on scope %s on %s/%s.",
+                  t->id,
+                  dns_transaction_key_string(t),
+                  dns_protocol_to_string(t->scope->protocol),
+                  t->scope->link ? t->scope->link->name : "*",
+                  t->scope->family == AF_UNSPEC ? "*" : af_to_name(t->scope->family));
 
         if (!t->initial_jitter_scheduled &&
             (t->scope->protocol == DNS_PROTOCOL_LLMNR ||
@@ -1356,12 +1357,7 @@ int dns_transaction_validate_dnssec(DnsTransaction *t) {
                 return 0;
         }
 
-        if (log_get_max_level() >= LOG_DEBUG) {
-                _cleanup_free_ char *ks = NULL;
-
-                (void) dns_resource_key_to_string(t->key, &ks);
-                log_debug("Validating response from transaction %" PRIu16 " (%s).", t->id, ks ? strstrip(ks) : "???");
-        }
+        log_debug("Validating response from transaction %" PRIu16 " (%s).", t->id, dns_transaction_key_string(t));
 
         /* First see if there are DNSKEYs we already known a validated DS for. */
         r = dns_transaction_validate_dnskey_by_ds(t);
@@ -1526,6 +1522,17 @@ int dns_transaction_validate_dnssec(DnsTransaction *t) {
         return 1;
 }
 
+const char *dns_transaction_key_string(DnsTransaction *t) {
+        assert(t);
+
+        if (!t->key_string) {
+                if (dns_resource_key_to_string(t->key, &t->key_string) < 0)
+                        return "n/a";
+        }
+
+        return strstrip(t->key_string);
+}
+
 static const char* const dns_transaction_state_table[_DNS_TRANSACTION_STATE_MAX] = {
         [DNS_TRANSACTION_NULL] = "null",
         [DNS_TRANSACTION_PENDING] = "pending",

diff --git a/src/resolve/resolved-dns-transaction.h b/src/resolve/resolved-dns-transaction.h
index 1f35a4dd8fa0930427fb2e3c9b44946bc542fb8e..ee5b78064404cd2c396ed5ed9e84eb07a04008ca 100644 (file)
--- a/src/resolve/resolved-dns-transaction.h
+++ b/src/resolve/resolved-dns-transaction.h
@@ -62,6 +62,7 @@ struct DnsTransaction {
         DnsScope *scope;
 
         DnsResourceKey *key;
+        char *key_string;
 
         DnsTransactionState state;
         DnssecResult dnssec_result;
@@ -136,6 +137,8 @@ void dns_transaction_notify(DnsTransaction *t, DnsTransaction *source);
 int dns_transaction_validate_dnssec(DnsTransaction *t);
 int dns_transaction_request_dnssec_keys(DnsTransaction *t);
 
+const char *dns_transaction_key_string(DnsTransaction *t);
+
 const char* dns_transaction_state_to_string(DnsTransactionState p) _const_;
 DnsTransactionState dns_transaction_state_from_string(const char *s) _pure_;