From 414a03e11d78c014e6cb6e406af36d3eb7d52857 Mon Sep 17 00:00:00 2001
From: Remi Gacogne <remi.gacogne@powerdns.com>
Date: Fri, 28 Feb 2020 17:21:19 +0100
Subject: [PATCH] Add 'queue full' metrics for our remote logger, log at debug
 only

---
 pdns/dnsdist.hh       |  1 -
 pdns/fstrm_logger.cc  |  7 +++++--
 pdns/fstrm_logger.hh  | 11 +++++++----
 pdns/remote_logger.cc | 15 +++++++++------
 pdns/remote_logger.hh |  7 ++++---
 5 files changed, 25 insertions(+), 16 deletions(-)

diff --git a/pdns/dnsdist.hh b/pdns/dnsdist.hh
index d1d9515452..c5c36167d5 100644
--- a/pdns/dnsdist.hh
+++ b/pdns/dnsdist.hh
@@ -33,7 +33,6 @@
 
 #include <boost/variant.hpp>
 
-#include "bpf-filter.hh"
 #include "capabilities.hh"
 #include "circular_buffer.hh"
 #include "dnscrypt.hh"
diff --git a/pdns/fstrm_logger.cc b/pdns/fstrm_logger.cc
index 62ccd72ebd..9e5608f947 100644
--- a/pdns/fstrm_logger.cc
+++ b/pdns/fstrm_logger.cc
@@ -195,13 +195,15 @@ void FrameStreamLogger::queueData(const std::string& data)
 
   if (res == fstrm_res_success) {
     // Frame successfully queued.
+    ++d_framesSent;
   } else if (res == fstrm_res_again) {
     free(frame);
 #ifdef RECURSOR
-    g_log<<Logger::Warning<<"FrameStreamLogger: queue full, dropping."<<std::endl;
+    g_log<<Logger::Debug<<"FrameStreamLogger: queue full, dropping."<<std::endl;
 #else
-    warnlog("FrameStreamLogger: queue full, dropping.");
+    vinfolog("FrameStreamLogger: queue full, dropping.");
 #endif
+    ++d_queueFullDrops;
  } else {
     // Permanent failure.
     free(frame);
@@ -210,6 +212,7 @@ void FrameStreamLogger::queueData(const std::string& data)
 #else
     warnlog("FrameStreamLogger: submitting to queue failed.");
 #endif
+    ++d_permanentFailures;
   }
 }
 
diff --git a/pdns/fstrm_logger.hh b/pdns/fstrm_logger.hh
index c6844a515d..a59e194b9d 100644
--- a/pdns/fstrm_logger.hh
+++ b/pdns/fstrm_logger.hh
@@ -37,11 +37,11 @@ class FrameStreamLogger : public RemoteLoggerInterface, boost::noncopyable
 {
 public:
   FrameStreamLogger(int family, const std::string& address, bool connect, const std::unordered_map<string,unsigned>& options = std::unordered_map<string,unsigned>());
-  virtual ~FrameStreamLogger();
-  virtual void queueData(const std::string& data) override;
-  virtual std::string toString() const override
+  ~FrameStreamLogger();
+  void queueData(const std::string& data) override;
+  std::string toString() const override
   {
-    return "FrameStreamLogger to " + d_address;
+    return "FrameStreamLogger to " + d_address + " (" + std::to_string(d_framesSent) + " frames sent, " + std::to_string(d_queueFullDrops) + " dropped, " + std::to_string(d_permanentFailures) + " permanent failures)";
   }
 
 private:
@@ -57,6 +57,9 @@ private:
   struct fstrm_writer *d_writer{nullptr};
   struct fstrm_iothr_options *d_iothropt{nullptr};
   struct fstrm_iothr *d_iothr{nullptr};
+  std::atomic<uint64_t> d_framesSent{0};
+  std::atomic<uint64_t> d_queueFullDrops{0};
+  std::atomic<uint64_t> d_permanentFailures{0};
 
   void cleanup();
 };
diff --git a/pdns/remote_logger.cc b/pdns/remote_logger.cc
index 69934b98a9..b277c7f191 100644
--- a/pdns/remote_logger.cc
+++ b/pdns/remote_logger.cc
@@ -54,11 +54,13 @@ void CircularWriteBuffer::flush()
     throw std::runtime_error("EOF");
   }
   //  cout<<"Flushed "<<res<<" bytes out of " << total <<endl;
-  if((size_t)res == d_buffer.size())
+  if (static_cast<size_t>(res) == d_buffer.size()) {
     d_buffer.clear();
+  }
   else {
-    while(res--)
+    while(res--) {
       d_buffer.pop_front();
+    }
   }
 }
 
@@ -96,17 +98,18 @@ bool RemoteLogger::reconnect()
 void RemoteLogger::queueData(const std::string& data)
 {
   if(!d_writer) {
-    d_drops++;
+    ++d_drops;
     return;
   }
   std::unique_lock<std::mutex> lock(d_mutex);
   if(d_writer) {
     try {
       d_writer->write(data);
+      ++d_queued;
     }
-    catch(std::exception& e) {
+    catch(const std::exception& e) {
       //      cout << "Got exception writing: "<<e.what()<<endl;
-      d_drops++;
+      ++d_drops;
       d_writer.reset();
       close(d_socket);
       d_socket = -1;
@@ -151,7 +154,7 @@ try
     sleep(d_reconnectWaitTime);
   }
 }
-catch(std::exception& e)
+catch(const std::exception& e)
 {
   cerr<<"Thead died on: "<<e.what()<<endl;
 }
diff --git a/pdns/remote_logger.hh b/pdns/remote_logger.hh
index d5356c2d3e..8bcf6b0528 100644
--- a/pdns/remote_logger.hh
+++ b/pdns/remote_logger.hh
@@ -89,22 +89,23 @@ public:
   void queueData(const std::string& data) override;
   std::string toString() const override
   {
-    return d_remote.toStringWithPort();
+    return d_remote.toStringWithPort() + " (" + std::to_string(d_queued) + " queued, " + std::to_string(d_drops) + " dropped)";
   }
   void stop()
   {
     d_exiting = true;
   }
-  std::atomic<uint32_t> d_drops{0};
 
 private:
   bool reconnect();
   void maintenanceThread();
 
+  std::unique_ptr<CircularWriteBuffer> d_writer;
   ComboAddress d_remote;
+  std::atomic<uint64_t> d_drops{0};
+  std::atomic<uint64_t> d_queued{0};
   uint64_t d_maxQueuedBytes;
   int d_socket{-1};
-  std::unique_ptr<CircularWriteBuffer> d_writer;
   uint16_t d_timeout;
   uint8_t d_reconnectWaitTime;
   std::atomic<bool> d_exiting{false};
-- 
2.47.2