]> gitweb.michael.orlitzky.com - djbdns-logparse.git/blobdiff - bin/djbdns-logparse.py
bin/djbdns-logparse.py: fix python3 integer division for txt records.
[djbdns-logparse.git] / bin / djbdns-logparse.py
index 5067116cce5acec4c12e7bbbf3f337314643dc65..8aa1837c3fce6f901408f73f278919666c40c105 100755 (executable)
@@ -3,10 +3,10 @@
 Convert tinydns and dnscache logs to human-readable form
 """
 
-import re
+import re, typing
 from struct import pack
-from time import strftime, gmtime
 from subprocess import Popen, PIPE
+from time import strftime, gmtime
 
 
 ## Regular expressions for matching tinydns/dnscache log lines. We
@@ -70,11 +70,15 @@ query_type = {
 
 # tinydns can drop a query for one of three reasons; this dictionary
 # maps the symbol that gets logged in each case to a human-readable
-# reason.
+# reason. We include the "+" case here, indicating that the query was
+# NOT dropped, to avoid a special case later on when we're formatting
+# the human-readable output.
 query_drop_reason = {
+    "+": None,
     "-": "no authority",
     "I": "invalid query",
     "C": "invalid class",
+    "/": "couldn't parse"
 }
 
 
@@ -124,7 +128,54 @@ def decode_type(words, i):
     qt = words[i]
     words[i] = query_type.get(int(qt), qt)
 
-def handle_dnscache_log(line, match):
+def handle_dnscache_log(line) -> typing.Optional[str]:
+    """
+    Handle a single log line if it matches the ``dnscache_log_re`` regex.
+
+    Parameters
+    ----------
+
+    line : string
+        The log line that might match ``dnscache_log_re``.
+
+    Returns
+    -------
+
+    Either the human-readable string if the log line was handled (that
+    is, if it was really a dnscache log line), or ``None`` if it was
+    not.
+
+    Examples
+    --------
+
+        >>> line = "2022-09-15 18:37:33.863805500 query 1 7f000001:a3db:4fb9 1 www.example.com."
+        >>> handle_dnscache_log(line)
+        '2022-09-15 18:37:33.863805500 query #1 127.0.0.1:41947 (id 20409) a www.example.com.'
+
+        >>> line = "2022-09-15 18:37:33.863874500 tx 0 1 www.example.com. . c0a80101"
+        >>> handle_dnscache_log(line)
+        '2022-09-15 18:37:33.863874500 tx g=0 a www.example.com. . 192.168.1.1'
+
+        >>> line = "2022-09-15 18:37:33.878529500 rr c0a80101 20865 1 www.example.com. 5db8d822"
+        >>> handle_dnscache_log(line)
+        '2022-09-15 18:37:33.878529500 rr 192.168.1.1 TTL=20865 a www.example.com. 93.184.216.34'
+
+        >>> line = "2022-09-15 18:37:33.878532500 stats 1 43 1 0"
+        >>> handle_dnscache_log(line)
+        '2022-09-15 18:37:33.878532500 stats count=1 motion=43 udp-active=1 tcp-active=0'
+
+        >>> line = "2022-09-15 18:37:33.878602500 sent 1 49"
+        >>> handle_dnscache_log(line)
+        '2022-09-15 18:37:33.878602500 sent #1 49'
+
+        >>> line = "this line is nonsense"
+        >>> handle_dnscache_log(line)
+
+    """
+    match = dnscache_log_re.match(line)
+    if not match:
+        return None
+
     (timestamp, event, data) = match.groups()
 
     words = data.split()
@@ -168,7 +219,7 @@ def handle_dnscache_log(line, match):
                     ellipsis = ""
                 length = int(response[0:2], 16)
                 chars = []
-                for i in range(1, len(response)/2):
+                for i in range(1, len(response)//2):
                     chars.append(chr(int(response[2*i : (2*i)+2], 16)))
                 words[4] = "%d:\"%s%s\"" % (length, "".join(chars), ellipsis)
 
@@ -193,32 +244,42 @@ def handle_dnscache_log(line, match):
     elif event in ("tcpopen", "tcpclose"):
         decode_client(words, 0)
 
-    print(timestamp, event, " ".join(words))
+    return f"{timestamp} {event} " + " ".join(words)
 
 
-def handle_tinydns_log(line : str, match: re.Match):
+
+def handle_tinydns_log(line : str) -> typing.Optional[str]:
     """
-    Handle a line that matched the ``tinydns_log_re`` regex.
+    Handle a single log line if it matches the ``tinydns_log_re`` regex.
 
     Parameters
     ----------
 
     line : string
-        The tinydns log line that matched ``tinydns_log_re``.
+        The log line that might match ``tinydns_log_re``.
+
+    Returns
+    -------
 
-    match : re.Match
-        The match object that was returned when ``line`` was
-        tested against ``tinydns_log_re``.
+    Either the human-readable string if the log line was handled (that
+    is, if it was really a tinydns log line), or ``None`` if it was
+    not.
 
     Examples
     --------
 
         >>> line = "2022-09-14 21:04:40.206516500 7f000001:9d61:be69 - 0001 www.example.com"
-        >>> match = tinydns_log_re.match(line)
-        >>> handle_tinydns_log(line, match)
-        2022-09-14 21:04:40.206516500 dropped query (no authority) from 127.0.0.1:40289 (id 48745): a www.example.com
+        >>> handle_tinydns_log(line)
+        '2022-09-14 21:04:40.206516500 dropped query (no authority) from 127.0.0.1:40289 (id 48745): a www.example.com'
+
+        >>> line = "this line is nonsense"
+        >>> handle_tinydns_log(line)
 
     """
+    match = tinydns_log_re.match(line)
+    if not match:
+        return None
+
     (timestamp, ip, port, id, code, type, name) = match.groups()
     ip = convert_ip(ip)
     port = int(port, 16)
@@ -230,24 +291,52 @@ def handle_tinydns_log(line : str, match: re.Match):
     type = int(type, 16)                # "001c" -> 28
     type = query_type.get(type, type)   # 28 -> "aaaa"
 
-    print(timestamp, end=' ')
+    line_tpl = "{timestamp} "
 
+    reason = query_drop_reason[code]
     if code == "+":
-        print ("sent response to %s:%s (id %s): %s %s"
-               % (ip, port, id, type, name))
-    elif code in ("-", "I", "C"):
-        reason = query_drop_reason[code]
-        print ("dropped query (%s) from %s:%s (id %s): %s %s"
-               % (reason, ip, port, id, type, name))
-    elif code == "/":
-        print ("dropped query (couldn't parse) from %s:%s"
-               % (ip, port))
+        line_tpl += "sent response to {ip}:{port} (id {id}): {type} {name}"
     else:
-        print ("%s from %s:%s (id %s): %s %s"
-               % (code, ip, port, id, type, name))
+        line_tpl += "dropped query ({reason}) from {ip}:{port}"
+        if code != "/":
+            # If the query can actually be parsed, the log line is a
+            # bit more informative than it would have been otherwise.
+            line_tpl += " (id {id}): {type} {name}"
+
+    return line_tpl.format(timestamp=timestamp,
+                           reason=reason,
+                           ip=ip,
+                           port=port,
+                           id=id,
+                           type=type,
+                           name=name)
+
+
+def parse_logfile(file : typing.TextIO):
+    r"""
+    Process a single log ``file``.
+
+    Parameters
+    ----------
 
+    file : typing.TextIO
+        An open log file, or stdin.
 
-def parse_logfile(file):
+    Examples
+    --------
+
+        >>> line = "@4000000063227a320c4f3114 7f000001:9d61:be69 - 0001 www.example.com\n"
+        >>> from tempfile import NamedTemporaryFile
+        >>> with NamedTemporaryFile(mode="w", delete=False) as f:
+        ...     _ = f.write(line)
+        >>> f = open(f.name, 'r')
+        >>> parse_logfile(f)
+        2022-09-14 21:04:40.206516500 dropped query (no authority) from 127.0.0.1:40289 (id 48745): a www.example.com
+        >>> f.close()
+        >>> from os import remove
+        >>> remove(f.name)
+
+    """
     # Open pipe to tai64nlocal: we will write lines of our input (the
     # raw log file) to it, and read log lines with readable timestamps
     # from it.
@@ -257,19 +346,21 @@ def parse_logfile(file):
         tai.stdin.write(line)
         line = tai.stdout.readline()
 
-        match = tinydns_log_re.match(line)
-        if match:
-            handle_tinydns_log(line, match)
-            continue
+        friendly_line = handle_tinydns_log(line)
+        if not friendly_line:
+            friendly_line = handle_dnscache_log(line)
+            if not friendly_line:
+                friendly_line = line
 
-        match = dnscache_log_re.match(line)
-        if match:
-            handle_dnscache_log(line, match)
-            continue
-
-        print(line)
+        print(friendly_line)
 
 def main():
+    r"""
+    The entry point to the program.
+
+    This function is responsible only for parsing any command-line
+    arguments, and then calling :func`parse_logfile` on them.
+    """
     # Create an argument parser using the file's docsctring as its
     # description.
     from argparse import ArgumentParser, FileType
@@ -285,12 +376,19 @@ def main():
                         default=[stdin],
                         help="djbdns logfile to process (default: stdin)")
 
+    # Warning: argparse automatically opens its file arguments here,
+    # and they only get closed when the program terminates. There's no
+    # real benefit to closing them one-at-a-time after calling
+    # parse_logfile(), because the "scarce" resource of open file
+    # descriptors gets consumed immediately, before any processing has
+    # happened. In other words, if you're going to run out of file
+    # descriptors, it's going to happen right now.
+    #
+    # So anyway, don't run this on several million logfiles.
     args = parser.parse_args()
     for f in args.logfiles:
         parse_logfile(f)
 
 
-
-
 if __name__ == "__main__":
     main()