From: bert hubert <bert.hubert@netherlabs.nl>
Date: Fri, 29 Sep 2017 20:37:49 +0000 (+0200)
Subject: Improve --quiet=false output for recursor to include DNSSEC and more timing details
X-Git-Tag: rec-4.1.0-rc1~10^2
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=2c9119cd208445b35ea9cbf411ff4d508fef72bd;p=thirdparty%2Fpdns.git

Improve --quiet=false output for recursor to include DNSSEC and more timing details
With this PR, pdns_recursor non-quiet logging shows DNSSEC status and adds time spent waiting for network, plus total time spent before answer was sent. This quantifies the internal overhead.
---

diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc
index 9be6586872..1875668f0b 100644
--- a/pdns/pdns_recursor.cc
+++ b/pdns/pdns_recursor.cc
@@ -1222,16 +1222,23 @@ static void startDoResolve(void *p)
         }
       }
     }
-
+    float spent=makeFloat(sr.getNow()-dc->d_now);
     if(!g_quiet) {
       L<<Logger::Error<<t_id<<" ["<<MT->getTid()<<"/"<<MT->numProcesses()<<"] answer to "<<(dc->d_mdp.d_header.rd?"":"non-rd ")<<"question '"<<dc->d_mdp.d_qname<<"|"<<DNSRecordContent::NumberToType(dc->d_mdp.d_qtype);
       L<<"': "<<ntohs(pw.getHeader()->ancount)<<" answers, "<<ntohs(pw.getHeader()->arcount)<<" additional, took "<<sr.d_outqueries<<" packets, "<<
-	sr.d_totUsec/1000.0<<" ms, "<<
-	sr.d_throttledqueries<<" throttled, "<<sr.d_timeouts<<" timeouts, "<<sr.d_tcpoutqueries<<" tcp connections, rcode="<<res<<endl;
+	sr.d_totUsec/1000.0<<" netw ms, "<< spent*1000.0<<" tot ms, "<<
+	sr.d_throttledqueries<<" throttled, "<<sr.d_timeouts<<" timeouts, "<<sr.d_tcpoutqueries<<" tcp connections, rcode="<< res;
+
+      if(!shouldNotValidate && sr.isDNSSECValidationRequested()) {
+	L<< ", dnssec="<<vStates[sr.getValidationState()];
+      }
+	
+      L<<endl;
+
     }
 
     sr.d_outqueries ? t_RC->cacheMisses++ : t_RC->cacheHits++;
-    float spent=makeFloat(sr.getNow()-dc->d_now);
+
     if(spent < 0.001)
       g_stats.answers0_1++;
     else if(spent < 0.010)