improved logging

button.py

@@ -1,5 +1,6 @@
 import json
 from dataclasses import dataclass
+from logging import Logger
 from typing import List
 
 from appdaemon.plugins.mqtt.mqttapi import Mqtt
@@ -14,10 +15,11 @@ class Button(Mqtt):
     button: str | List[str]
     rich: bool = False
     config: ButtonConfig
+    logger: Logger
 
     async def initialize(self):
         self.config = ButtonConfig(**self.args)
-        setup_component_logging(self)
+        self.logger = setup_component_logging(self)
         self.app: RoomController = await self.get_app(self.args['app'])
         self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG')
 
@@ -34,7 +36,9 @@ class Button(Mqtt):
     def setup_button(self, name: str):
         topic = f'zigbee2mqtt/{name}'
         # self.mqtt_subscribe(topic, namespace='mqtt')
-        self.listen_event(self.handle_button, 'MQTT_MESSAGE', topic=topic, namespace='mqtt', button=name)
+        self.listen_event(
+            self.handle_button, 'MQTT_MESSAGE', topic=topic, namespace='mqtt', button=name
+        )
         self.log(f'MQTT topic [topic]{topic}[/] controls app [room]{self.app.name}[/]')
 
     def handle_button(self, event_name, data, kwargs):

console.py

@@ -6,6 +6,7 @@ from dataclasses import asdict, dataclass
 from appdaemon.logging import AppNameFormatter
 from rich.console import Console
 from rich.highlighter import RegexHighlighter
+from rich.logging import RichHandler
 from rich.theme import Theme
 
 
@@ -25,7 +26,7 @@ console = Console(
     theme=Theme(
         {
             'log.time': 'none',
-            'logging.level.info': 'none',
+            # 'logging.level.info': 'none',
             'room': 'italic bright_cyan',
             'component': 'dark_violet',
             'friendly_name': 'yellow',
@@ -44,7 +45,7 @@ console = Console(
 
 
 class ContextSettingFilter(logging.Filter):
-    def filter(self, record: logging.LogRecord):
+    def filter(self, record: logging.LogRecord) -> logging.LogRecord:
         for name, val in asdict(self).items():
             setattr(record, name, val)
         return record
@@ -56,21 +57,21 @@ class RoomControllerFilter(ContextSettingFilter):
     component: str
 
 
-class UnMarkupFormatter(AppNameFormatter):
+class UnMarkupFilter(logging.Filter):
     md_regex = re.compile(r'(?P<open>\[.*?\])(?P<text>.*?)(?P<close>\[\/\])')
 
-    def format(self, record: logging.LogRecord):
+    def filter(self, record: logging.LogRecord) -> logging.LogRecord:
-        result = super().format(record)
+        record.msg = self.md_regex.sub(r'\g<text>', record.msg)
-        return self.md_regex.sub(r'\g<text>', result)
+        return record
 
 
 def create_rich_logging_dict(parent_room: str, typ: str = None):
-    logger_name = f'room_control.{parent_room}'
+    logger_name = f'AppDaemon.{parent_room}'
     if typ is not None:
         logger_name += f'.{typ}'
-        fmt = '[room]{room:>12}[/] [component]{component:<9}[/]{message}'
+        fmt = '[room]{room:>10}[/] [component]{component:<9}[/] {message}'
     else:
-        fmt = '[room]{room:>12}[/] {message}'
+        fmt = '[room]{room:>10}[/] {message}'
 
     LOG_CFG = {
         'version': 1,
@@ -78,44 +79,56 @@ def create_rich_logging_dict(parent_room: str, typ: str = None):
         'filters': {
             logger_name: {
                 '()': 'console.RoomControllerFilter',
-                # '.': {'room': parent_room, 'component': typ},
                 'room': parent_room,
                 'component': typ,
-            }
+            },
+            'unmarkup': {'()': 'console.UnMarkupFilter'},
         },
         'formatters': {
-            logger_name: {
+            'basic': {'style': '{', 'format': fmt, 'datefmt': '%H:%M:%S.%f'},
+            'err': {
                 'style': '{',
-                'format': fmt,
+                'format': '{asctime}.{msecs:02.0f} {room} {message}',
-                # 'datefmt': '%Y-%m-%d %I:%M:%S %p',
+                'datefmt': '%I:%M:%S',
-            }
+            },
         },
         'handlers': {
             logger_name: {
                 'filters': [logger_name],
-                'formatter': logger_name,
+                'formatter': 'basic',
                 '()': 'rich.logging.RichHandler',
                 'markup': True,
-                'log_time_format': '%Y-%m-%d %I:%M:%S %p',
                 'show_path': False,
+                # 'show_time': False,
                 'omit_repeated_times': False,
-                'highlighter': RCHighlighter(),
                 'console': console,
             },
+            'stderr': {
+                'filters': [logger_name, 'unmarkup'],
+                'formatter': 'err',
+                'class': 'logging.StreamHandler',
+                'stream': 'ext://sys.stderr',
+            },
         },
         'loggers': {
             logger_name: {
                 'level': 'INFO',
                 'propagate': False,
-                'handlers': [logger_name],
+                'handlers': [
+                    logger_name,
+                    # 'stderr'
+                ],
             }
         },
     }
     return LOG_CFG
 
 
-def setup_component_logging(self):
+def setup_component_logging(self) -> logging.Logger:
-    cfg_dict = create_rich_logging_dict(parent_room=self.args['app'], typ=type(self).__name__)
+    """Creates a logger for a subcomponent with a RichHandler"""
+    typ = type(self).__name__
+    parent = self.args['app']
+    cfg_dict = create_rich_logging_dict(parent_room=parent, typ=typ)
     logger_name = next(iter(cfg_dict['loggers']))
 
     try:
@@ -123,4 +136,4 @@ def setup_component_logging(self):
     except Exception:
         console.print_exception()
     else:
-        self.logger = logging.getLogger(logger_name)
+        return logging.getLogger(logger_name)

door.py

@@ -1,3 +1,4 @@
+from logging import Logger
 from appdaemon.plugins.hass.hassapi import Hass
 from console import setup_component_logging
 
@@ -5,8 +6,10 @@ from room_control import RoomController
 
 
 class Door(Hass):
+    logger: Logger
+
     async def initialize(self):
-        setup_component_logging(self)
+        self.logger = setup_component_logging(self)
         self.app: RoomController = await self.get_app(self.args['app'])
         self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG')
 

motion.py

@@ -1,3 +1,4 @@
+from logging import Logger
 import re
 from datetime import timedelta
 from typing import Literal, Optional
@@ -25,6 +26,8 @@ Callbacks = dict[str, dict[str, CallbackEntry]]
 
 
 class Motion(Hass):
+    logger: Logger
+
     @property
     def sensor(self) -> Entity:
         return self.get_entity(self.args['sensor'])
@@ -42,7 +45,7 @@ class Motion(Hass):
         return self.ref_entity.get_state() == 'on'
 
     def initialize(self):
-        setup_component_logging(self)
+        self.logger = setup_component_logging(self)
         self.app: RoomController = self.get_app(self.args['app'])
         self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG')
 

room_control.py

@@ -35,6 +35,7 @@ class RoomController(Hass, Mqtt):
     def initialize(self):
         cfg_dict = create_rich_logging_dict(parent_room=self.name)
         logging.config.dictConfig(cfg_dict)
+        self.logger = logging.getLogger(next(iter(cfg_dict['loggers'])))
 
         self.app_entities = self.gather_app_entities()
         # self.log(f'entities: {self.app_entities}')