From b4e8258de161e583af94c9ad00835ca5ef5916ee Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Odd=20Str=C3=A5b=C3=B8?= <oddstr13@openshell.no>
Date: Mon, 18 Dec 2023 14:26:56 +0100
Subject: [PATCH] Improve logging of dictionaries

---
 srnemqtt/__main__.py | 21 +++++++++++++++------
 srnemqtt/util.py     | 32 +++++++++++++++++++++++++++++++-
 2 files changed, 46 insertions(+), 7 deletions(-)

diff --git a/srnemqtt/__main__.py b/srnemqtt/__main__.py
index 2a520d7..1fed6c5 100755
--- a/srnemqtt/__main__.py
+++ b/srnemqtt/__main__.py
@@ -3,6 +3,7 @@
 
 import time
 from logging import getLogger
+from logging import root as logging_root
 from logging.config import dictConfig as loggingDictConfig
 
 from bluepy.btle import BTLEDisconnectError  # type: ignore
@@ -10,9 +11,9 @@ from serial import SerialException  # type: ignore
 
 from .config import get_config, get_consumers, get_interface
 from .protocol import ChargeController
-from .util import Periodical
+from .util import LazyJSON, LoggingDictFilter, Periodical
 
-logger = getLogger(__name__)
+logger = getLogger("SolarMPPT")
 
 
 class CommunicationError(BTLEDisconnectError, SerialException, IOError):
@@ -23,6 +24,10 @@ def main():
     conf = get_config()
 
     loggingDictConfig(conf.get("logging", {}))
+    logging_dict_filter = LoggingDictFilter()
+    logging_dict_filter.data["service"] = "SolarMPPT"
+    logging_root.addFilter(logging_dict_filter)
+
     consumers = get_consumers(conf)
 
     per_voltages = Periodical(interval=15)
@@ -33,9 +38,13 @@ def main():
             try:
                 logger.info("Connecting...")
                 with get_interface() as dev:
+                    cc = ChargeController(dev)
+                    logging_dict_filter.data["srne_model"] = cc.model
+                    logging_dict_filter.data["srne_version"] = cc.version
+                    logging_dict_filter.data["srne_serial"] = cc.serial
+
                     logger.info("Connected.")
 
-                    cc = ChargeController(dev)
                     logger.info(f"Controller model: {cc.model}")
                     logger.info(f"Controller version: {cc.version}")
                     logger.info(f"Controller serial: {cc.serial}")
@@ -62,7 +71,7 @@ def main():
                     for i in range(min(days, 4)):
                         hist = cc.get_historical(i)
                         res = hist.as_dict()
-                        logger.debug({i: res})
+                        logger.debug(LazyJSON({i: res}))
                         for consumer in consumers:
                             consumer.write({str(i): res})
 
@@ -71,14 +80,14 @@ def main():
 
                         if per_voltages(now):
                             data = cc.state.as_dict()
-                            logger.debug(data)
+                            logger.debug(LazyJSON(data))
                             for consumer in consumers:
                                 consumer.write(data)
 
                         if per_current_hist(now):
                             data = cc.today.as_dict()
                             data.update(cc.extra.as_dict())
-                            logger.debug(data)
+                            logger.debug(LazyJSON(data))
                             for consumer in consumers:
                                 consumer.write(data)
 
diff --git a/srnemqtt/util.py b/srnemqtt/util.py
index 254e38b..a95f68f 100644
--- a/srnemqtt/util.py
+++ b/srnemqtt/util.py
@@ -1,7 +1,11 @@
 # -*- coding: utf-8 -*-
+import json
 import time
+from logging import Filter as LoggingFilter
 from logging import getLogger
-from typing import Optional
+from typing import Dict, Optional
+
+__all__ = ["humanize_number", "Periodical", "LazyJSON", "LoggingDictFilter"]
 
 # Only factor of 1000
 SI_PREFIXES_LARGE = "kMGTPEZY"
@@ -35,6 +39,32 @@ def humanize_number(data, unit: str = ""):
     return f"{data:.3g} {prefix}{unit}"
 
 
+class LazyJSON:
+    def __init__(self, data):
+        self.data = data
+
+    def __str__(self) -> str:
+        return json.dumps(self.data)
+
+    def __repr__(self) -> str:
+        return repr(self.data)
+
+
+class LoggingDictFilter(LoggingFilter):
+    data: Dict[str, str]
+
+    def __init__(self):
+        self.data = {}
+
+    def filter(self, record):
+        print(self.data)
+        for key, value in self.data.items():
+            print(key, value)
+            assert not hasattr(record, key)
+            setattr(record, key, value)
+        return True
+
+
 class Periodical:
     prev: float
     interval: float