]> granicus.if.org Git - pdns/commitdiff
dnsdist: Add more options to LogAction (non-verbose mode, timestamps)
authorRemi Gacogne <remi.gacogne@powerdns.com>
Fri, 11 Oct 2019 15:16:37 +0000 (17:16 +0200)
committerRemi Gacogne <remi.gacogne@powerdns.com>
Fri, 11 Oct 2019 15:16:37 +0000 (17:16 +0200)
contrib/DNSDistLogActionReader.py [new file with mode: 0644]
pdns/dnsdist-lua-actions.cc
pdns/dnsdistdist/docs/rules-actions.rst

diff --git a/contrib/DNSDistLogActionReader.py b/contrib/DNSDistLogActionReader.py
new file mode 100644 (file)
index 0000000..8bdd4ec
--- /dev/null
@@ -0,0 +1,61 @@
+#!/usr/bin/env python
+
+import socket
+import struct
+import sys
+
+def readRecord(fp, withTimestamp):
+
+    if withTimestamp:
+        data = fp.read(12)
+        if not data:
+            return False
+        tv_sec, tv_nsec = struct.unpack("QI", data)
+
+    data = fp.read(2)
+    if not data:
+        return False
+
+    queryID = struct.unpack("!H", data)[0]
+    qname = ''
+    while True:
+        labelLen = struct.unpack("B", fp.read(1))[0]
+        if labelLen == 0:
+            break
+        label = fp.read(labelLen)
+        if qname != '':
+            qname = qname + '.'
+        qname = qname + label.decode()
+
+    qtype = struct.unpack("H", fp.read(2))[0]
+    addrType = struct.unpack("H", fp.read(2))[0]
+    addr = None
+    if addrType == socket.AF_INET:
+        addr = socket.inet_ntop(socket.AF_INET, fp.read(4))
+    elif addrType == socket.AF_INET6:
+        addr = socket.inet_ntop(socket.AF_INET6, fp.read(16))
+    else:
+        print('Unsupported address type %d, skipping this record' % (int(addrType)))
+        return False
+    port = struct.unpack("!H", fp.read(2))[0]
+
+    if withTimestamp:
+        print('[%u.%u] Packet from %s:%d for %s %s with id %d' % (tv_sec, tv_nsec, addr, port, qname, qtype, queryID))
+    else:
+        print('Packet from %s:%d for %s %s with id %d' % (addr, port, qname, qtype, queryID))
+
+    return True
+
+def readLogFile(filename, withTimestamps):
+    with open(filename, mode='rb') as fp:
+        while True:
+            if not readRecord(fp, withTimestamps):
+                break
+
+if __name__ == "__main__":
+    if len(sys.argv) != 2 and (len(sys.argv) != 3 or sys.argv[2] != 'with-timestamps'):
+        sys.exit('Usage: %s <path to log file> [with-timestamps]' % (sys.argv[0]))
+
+    readLogFile(sys.argv[1], len(sys.argv) == 3)
+
+    sys.exit(0)
index 7e16700c80f0f910fe32339c5fa0b03cfe7ef6d6..3cc60124c799e62a7f7e2e744f501abb50f79ff8 100644 (file)
@@ -550,44 +550,70 @@ public:
 class LogAction : public DNSAction, public boost::noncopyable
 {
 public:
-  LogAction() : d_fp(0)
+  LogAction(): d_fp(nullptr, fclose)
   {
   }
-  LogAction(const std::string& str, bool binary=true, bool append=false, bool buffered=true) : d_fname(str), d_binary(binary)
+
+  LogAction(const std::string& str, bool binary=true, bool append=false, bool buffered=true, bool verboseOnly=true, bool includeTimestamp=false): d_fname(str), d_binary(binary), d_verboseOnly(verboseOnly), d_includeTimestamp(includeTimestamp)
   {
     if(str.empty())
       return;
     if(append)
-      d_fp = fopen(str.c_str(), "a+");
+      d_fp = std::unique_ptr<FILE, int(*)(FILE*)>(fopen(str.c_str(), "a+"), fclose);
     else
-      d_fp = fopen(str.c_str(), "w");
+      d_fp = std::unique_ptr<FILE, int(*)(FILE*)>(fopen(str.c_str(), "w"), fclose);
     if(!d_fp)
       throw std::runtime_error("Unable to open file '"+str+"' for logging: "+stringerror());
     if(!buffered)
-      setbuf(d_fp, 0);
-  }
-  ~LogAction() override
-  {
-    if(d_fp)
-      fclose(d_fp);
+      setbuf(d_fp.get(), 0);
   }
+
   DNSAction::Action operator()(DNSQuestion* dq, std::string* ruleresult) const override
   {
-    if(!d_fp) {
-      vinfolog("Packet from %s for %s %s with id %d", dq->remote->toStringWithPort(), dq->qname->toString(), QType(dq->qtype).getName(), dq->dh->id);
+    if (!d_fp) {
+      if (!d_verboseOnly || g_verbose) {
+        if (d_includeTimestamp) {
+          infolog("[%u.%u] Packet from %s for %s %s with id %d", static_cast<unsigned long long>(dq->queryTime->tv_sec), static_cast<unsigned long>(dq->queryTime->tv_nsec), dq->remote->toStringWithPort(), dq->qname->toString(), QType(dq->qtype).getName(), dq->dh->id);
+        }
+        else {
+          infolog("Packet from %s for %s %s with id %d", dq->remote->toStringWithPort(), dq->qname->toString(), QType(dq->qtype).getName(), dq->dh->id);
+        }
+      }
     }
     else {
-      if(d_binary) {
+      if (d_binary) {
         std::string out = dq->qname->toDNSString();
-        fwrite(out.c_str(), 1, out.size(), d_fp);
-        fwrite((void*)&dq->qtype, 1, 2, d_fp);
+        if (d_includeTimestamp) {
+          uint64_t tv_sec = static_cast<uint64_t>(dq->queryTime->tv_sec);
+          uint32_t tv_nsec = static_cast<uint32_t>(dq->queryTime->tv_nsec);
+          fwrite(&tv_sec, sizeof(tv_sec), 1, d_fp.get());
+          fwrite(&tv_nsec, sizeof(tv_nsec), 1, d_fp.get());
+        }
+        uint16_t id = dq->dh->id;
+        fwrite(&id, sizeof(id), 1, d_fp.get());
+        fwrite(out.c_str(), 1, out.size(), d_fp.get());
+        fwrite(&dq->qtype, sizeof(dq->qtype), 1, d_fp.get());
+        fwrite(&dq->remote->sin4.sin_family, sizeof(dq->remote->sin4.sin_family), 1, d_fp.get());
+        if (dq->remote->sin4.sin_family == AF_INET) {
+          fwrite(&dq->remote->sin4.sin_addr.s_addr, sizeof(dq->remote->sin4.sin_addr.s_addr), 1, d_fp.get());
+        }
+        else if (dq->remote->sin4.sin_family == AF_INET6) {
+          fwrite(&dq->remote->sin6.sin6_addr.s6_addr, sizeof(dq->remote->sin6.sin6_addr.s6_addr), 1, d_fp.get());
+        }
+        fwrite(&dq->remote->sin4.sin_port, sizeof(dq->remote->sin4.sin_port), 1, d_fp.get());
       }
       else {
-        fprintf(d_fp, "Packet from %s for %s %s with id %d\n", dq->remote->toStringWithPort().c_str(), dq->qname->toString().c_str(), QType(dq->qtype).getName().c_str(), dq->dh->id);
+        if (d_includeTimestamp) {
+          fprintf(d_fp.get(), "[%llu.%lu] Packet from %s for %s %s with id %d\n", static_cast<unsigned long long>(dq->queryTime->tv_sec), static_cast<unsigned long>(dq->queryTime->tv_nsec), dq->remote->toStringWithPort().c_str(), dq->qname->toString().c_str(), QType(dq->qtype).getName().c_str(), dq->dh->id);
+        }
+        else {
+          fprintf(d_fp.get(), "Packet from %s for %s %s with id %d\n", dq->remote->toStringWithPort().c_str(), dq->qname->toString().c_str(), QType(dq->qtype).getName().c_str(), dq->dh->id);
+        }
       }
     }
     return Action::None;
   }
+
   std::string toString() const override
   {
     if (!d_fname.empty()) {
@@ -597,8 +623,10 @@ public:
   }
 private:
   std::string d_fname;
-  FILE* d_fp{0};
+  std::unique_ptr<FILE, int(*)(FILE*)> d_fp{nullptr, fclose};
   bool d_binary{true};
+  bool d_verboseOnly{true};
+  bool d_includeTimestamp{false};
 };
 
 
@@ -1292,8 +1320,8 @@ void setupLuaActions()
       return std::shared_ptr<DNSAction>(new DisableValidationAction);
     });
 
-  g_lua.writeFunction("LogAction", [](const std::string& fname, boost::optional<bool> binary, boost::optional<bool> append, boost::optional<bool> buffered) {
-      return std::shared_ptr<DNSAction>(new LogAction(fname, binary ? *binary : true, append ? *append : false, buffered ? *buffered : false));
+  g_lua.writeFunction("LogAction", [](boost::optional<std::string> fname, boost::optional<bool> binary, boost::optional<bool> append, boost::optional<bool> buffered, boost::optional<bool> verboseOnly, boost::optional<bool> includeTimestamp) {
+      return std::shared_ptr<DNSAction>(new LogAction(fname ? *fname : "", binary ? *binary : true, append ? *append : false, buffered ? *buffered : false, verboseOnly ? *verboseOnly : true, includeTimestamp ? *includeTimestamp : false));
     });
 
   g_lua.writeFunction("RCodeAction", [](uint8_t rcode) {
index 3084481fb620375686d9ef3e7adb49bc295b7d2f..e72c1f445cab898cc0998d900669aab40966792f 100644 (file)
@@ -988,18 +988,28 @@ The following actions exist.
   :param KeyValueLookupKey lookupKey: The key to use for the lookup
   :param string destinationTag: The name of the tag to store the result into
 
-.. function:: LogAction(filename[, binary[, append[, buffered]]])
+.. function:: LogAction([filename[, binary[, append[, buffered[, verboseOnly[, includeTimestamp]]]]]])
+
+  .. versionchanged:: 1.4.0
+    Added the optional parameters ``verboseOnly`` and ``includeTimestamp``, made ``filename`` optional.
 
   Log a line for each query, to the specified ``file`` if any, to the console (require verbose) if the empty string is given as filename.
-  When logging to a file, the ``binary`` optional parameter specifies whether we log in binary form (default) or in textual form.
+
+  If an empty string is supplied in the file name, the logging is done to stdout, and only in verbose mode by default. This can be changed by setting ``verboseOnly`` to true.
+
+  When logging to a file, the ``binary`` optional parameter specifies whether we log in binary form (default) or in textual form. Before 1.4.0 the binary log format only included the qname and qtype. Since 1.4.0 it includes an optional timestamp, the query ID, qname, qtype, remote address and port.
+
   The ``append`` optional parameter specifies whether we open the file for appending or truncate each time (default).
   The ``buffered`` optional parameter specifies whether writes to the file are buffered (default) or not.
+
   Subsequent rules are processed after this action.
 
   :param string filename: File to log to. Set to an empty string to log to the normal stdout log, this only works when ``-v`` is set on the command line.
   :param bool binary: Do binary logging. Default true
   :param bool append: Append to the log. Default false
-  :param bool buffered: Use buffered I/O. default true
+  :param bool buffered: Use buffered I/O. Default true
+  :param bool verboseOnly: Whether to log only in verbose mode when logging to stdout. Default is true
+  :param bool includeTimestamp: Whether to include a timestamp for every entry. Default is false
 
 .. function:: LuaAction(function)