enhanced logging to be more verbose

polytope_server/common/logging.py

@@ -21,63 +21,64 @@
 import datetime
 import json
 import logging
+import socket
 
 indexable_fields = {"request_id": str}
 
 
-def setup(config, source_name):
-
-    # Override the default logger
-
-    logger = logging.getLogger()
-    logger.name = source_name
-    handler = logging.StreamHandler()
-    handler.setLevel(logging.DEBUG)
-
-    mode = config.get("logging", {}).get("mode", "json")
-    level = config.get("logging", {}).get("level", "INFO")
-
-    handler.setFormatter(LogFormatter(mode))
-    logger.addHandler(handler)
-    logger.setLevel(level)
-
-    logger.info("Logging Initialized")
-
-
 class LogFormatter(logging.Formatter):
     def __init__(self, mode):
         super(LogFormatter, self).__init__()
         self.mode = mode
 
     def format(self, record):
-
-        msg = super(LogFormatter, self).format(record)
-
-        result = {}
-        result["ts"] = datetime.datetime.utcnow().isoformat()[:-3] + "Z"
-        result["src"] = str(record.name)
-        result["lvl"] = str(record.levelname)
-        result["pth"] = str("{}:{}".format(record.pathname, record.lineno))
-        result["msg"] = str(msg)
-
-        # log accepts extra={} args to eg. logging.debug
-        # if the extra arguments match known indexable_fields these are added to the log
-        # these strongly-typed fields can be used for indexing of logs
+        # timezone-aware datetime object
+        utc_time = datetime.datetime.fromtimestamp(record.created, datetime.timezone.utc)
+        formatted_time = utc_time.strftime("%Y-%m-%d %H:%M:%S,%f")[:-3]
+
+        result = {
+            "asctime": formatted_time,
+            "hostname": getattr(record, "hostname", socket.gethostname()),
+            "process": record.process,
+            "thread": record.thread,
+            "name": record.name,
+            "filename": record.filename,
+            "lineno": record.lineno,
+            "levelname": record.levelname,
+            "message": record.getMessage(),
+        }
 
         if self.mode == "console":
-            return result["ts"] + " | " + result["msg"]
-
+            return result["asctime"] + " | " + result["message"]
         else:
+            # following adds extra fields to the log message
             for name, typ in indexable_fields.items():
                 if hasattr(record, name):
                     val = getattr(record, name)
                     if isinstance(val, typ):
                         result[name] = val
                     else:
                         raise TypeError("Extra information with key {} is expected to be of type {}".format(name, typ))
-
-            if self.mode == "prettyprint":
-                indent = 2
+            if self.mode == "logserver":
+                # Ensuring single line output
+                return json.dumps(result, indent=None)
+            elif self.mode == "prettyprint":
+                return json.dumps(result, indent=2)
             else:
-                indent = 0
-            return json.dumps(result, indent=indent, sort_keys=True)
+                return json.dumps(result, indent=0)
+
+
+def setup(config, source_name):
+    logger = logging.getLogger()
+    logger.name = source_name
+    handler = logging.StreamHandler()
+    handler.setLevel(logging.DEBUG)
+
+    mode = config.get("logging", {}).get("mode", "json")
+    level = config.get("logging", {}).get("level", "INFO")
+
+    handler.setFormatter(LogFormatter(mode))
+    logger.addHandler(handler)
+    logger.setLevel(level)
+
+    logger.info("Logging Initialized")