rich logging config in yaml file in package data

This commit is contained in:
John Lancaster
2024-05-07 23:38:42 -05:00
parent 7b67d062a0
commit 463a68a27a
8 changed files with 170 additions and 110 deletions

View File

@@ -0,0 +1,26 @@
version: 1
disable_existing_loggers: false
formatters:
rich:
style: "{"
format: "[room]{room}[/] {message}"
# format: "{message}"
datefmt: '%H:%M:%S.%f'
rich_component:
style: "{"
format: "[room]{room}[/] [component]{component}[/] {message}"
# format: "{message}"
datefmt: '%H:%M:%S.%f'
handlers:
rich:
formatter: rich
'()': 'rich.logging.RichHandler'
markup: True
show_path: false
omit_repeated_times: false
rich_component:
formatter: rich_component
'()': 'rich.logging.RichHandler'
markup: True
show_path: false
omit_repeated_times: false

View File

@@ -5,7 +5,7 @@ from typing import TYPE_CHECKING, List
from appdaemon.plugins.mqtt.mqttapi import Mqtt from appdaemon.plugins.mqtt.mqttapi import Mqtt
from .console import setup_component_logging from . import console
from .model import ButtonConfig from .model import ButtonConfig
if TYPE_CHECKING: if TYPE_CHECKING:
@@ -20,9 +20,9 @@ class Button(Mqtt):
logger: Logger logger: Logger
async def initialize(self): async def initialize(self):
self.config = ButtonConfig(**self.args)
self.logger = setup_component_logging(self)
self.app: 'RoomController' = await self.get_app(self.args['app']) self.app: 'RoomController' = await self.get_app(self.args['app'])
self.logger = console.load_rich_config(self.app.name, type(self).__name__)
self.config = ButtonConfig(**self.args)
self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG') self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG')
self.button = self.config.button self.button = self.config.button

View File

@@ -1,9 +1,12 @@
import json
import logging import logging
import logging.config import logging.config
import re import re
from abc import ABC from abc import ABC
from dataclasses import asdict from dataclasses import asdict
from importlib.resources import files
import yaml
from rich.console import Console from rich.console import Console
from rich.highlighter import RegexHighlighter from rich.highlighter import RegexHighlighter
from rich.theme import Theme from rich.theme import Theme
@@ -42,6 +45,40 @@ class RCHighlighter(RegexHighlighter):
] ]
def load_rich_config(
room: str = None, component: str = None, level: str = 'INFO'
) -> logging.LoggerAdapter:
logger_name = f'Appdaemon.{room}'
if component is not None:
logger_name += f'.{component}'
with files('room_control').joinpath('.rich_logging.yaml').open('r') as f:
RICH_CFG = yaml.safe_load(f)
RICH_CFG['handlers']['rich']['console'] = console
RICH_CFG['handlers']['rich']['highlighter'] = RCHighlighter()
RICH_CFG['handlers']['rich_component']['console'] = console
RICH_CFG['handlers']['rich_component']['highlighter'] = RCHighlighter()
RICH_CFG['loggers'] = {
logger_name: {
'handlers': ['rich' if component is None else 'rich_component'],
'propagate': False,
'level': level,
}
}
extra = {'room': room}
if component is not None:
extra['component'] = component
logging.config.dictConfig(RICH_CFG)
logger = logging.getLogger(logger_name)
adapter = logging.LoggerAdapter(logger, extra)
return adapter
RICH_HANDLER_CFG = { RICH_HANDLER_CFG = {
'()': 'rich.logging.RichHandler', '()': 'rich.logging.RichHandler',
'markup': True, 'markup': True,
@@ -61,19 +98,19 @@ class ContextSettingFilter(logging.Filter, ABC):
return record return record
class RoomFilter(logging.Filter):
"""Used to filter out messages that have a component field because they will have already been printed by their respective logger."""
def filter(self, record: logging.LogRecord) -> bool:
return getattr(record, 'component', None) is None
# @dataclass # @dataclass
# class RoomControllerFilter(ContextSettingFilter): # class RoomControllerFilter(ContextSettingFilter):
# room: str # room: str
# component: Optional[str] = None # component: Optional[str] = None
class RoomFilter(logging.Filter):
"""Used to filter out messages that have a component field because they will have already been printed by their respective logger."""
def filter(self, record: logging.LogRecord) -> bool:
return not hasattr(record, 'component')
# class RoomControllerFormatter(logging.Formatter): # class RoomControllerFormatter(logging.Formatter):
# def format(self, record: logging.LogRecord): # def format(self, record: logging.LogRecord):
# return super().format(record) # return super().format(record)
@@ -87,6 +124,11 @@ class UnMarkupFilter(logging.Filter):
return record return record
class JSONFormatter(logging.Formatter):
def format(self, record: logging.LogRecord) -> str:
return json.dumps(record.__dict__)
def room_logging_config(name: str): def room_logging_config(name: str):
return { return {
'version': 1, 'version': 1,
@@ -106,6 +148,7 @@ def room_logging_config(name: str):
'format': '{asctime}.{msecs:03.0f} {levelname:8} {name}: {message}', 'format': '{asctime}.{msecs:03.0f} {levelname:8} {name}: {message}',
'datefmt': '%Y-%m-%d %H:%M:%S', 'datefmt': '%Y-%m-%d %H:%M:%S',
}, },
'json': {'()': 'room_control.console.JSONFormatter'},
}, },
'handlers': { 'handlers': {
'rich_room': { 'rich_room': {
@@ -119,7 +162,14 @@ def room_logging_config(name: str):
'class': 'logging.handlers.RotatingFileHandler', 'class': 'logging.handlers.RotatingFileHandler',
# 'class': 'logging.FileHandler', # 'class': 'logging.FileHandler',
'filename': f'/logs/{name}.log', 'filename': f'/logs/{name}.log',
'mode': 'w', 'maxBytes': 1000000,
'backupCount': 3,
},
'json': {
'filters': ['unmarkup'],
'formatter': 'json',
'filename': f'/logs/{name}.jsonl',
'class': 'logging.handlers.RotatingFileHandler',
'maxBytes': 1000000, 'maxBytes': 1000000,
'backupCount': 3, 'backupCount': 3,
}, },
@@ -128,54 +178,60 @@ def room_logging_config(name: str):
f'AppDaemon.{name}': { f'AppDaemon.{name}': {
'level': 'INFO', 'level': 'INFO',
'propagate': False, 'propagate': False,
'handlers': ['rich_room', 'file'], 'handlers': [
'rich_room',
'file',
'json',
],
}, },
}, },
} }
def component_logging_config(parent_room: str, component: str): # def component_logging_config(parent_room: str, component: str):
logger_name = f'AppDaemon.{parent_room}.{component}' # logger_name = f'AppDaemon.{parent_room}.{component}'
LOG_CFG = { # cfg = load_rich_config()
'version': 1,
'disable_existing_loggers': False, # LOG_CFG = {
'formatters': { # 'version': 1,
'rich_component': { # 'disable_existing_loggers': False,
'style': '{', # 'formatters': {
'format': '[room]{room}[/] [component]{component}[/] {message}', # 'rich_component': {
'datefmt': '%H:%M:%S.%f', # 'style': '{',
}, # 'format': '[room]{room}[/] [component]{component}[/] {message}',
}, # 'datefmt': '%H:%M:%S.%f',
'handlers': { # },
'rich_component': { # },
'formatter': 'rich_component', # 'handlers': {
**RICH_HANDLER_CFG, # 'rich_component': {
}, # 'formatter': 'rich_component',
}, # **RICH_HANDLER_CFG,
'loggers': { # },
logger_name: { # },
# 'level': 'INFO', # 'loggers': {
'propagate': True, # logger_name: {
'handlers': ['rich_component'], # # 'level': 'INFO',
} # 'propagate': True,
}, # 'handlers': ['rich_component'],
} # }
return LOG_CFG # },
# }
# return LOG_CFG
def setup_component_logging(self) -> logging.Logger: # def setup_component_logging(self) -> logging.Logger:
"""Creates a logger for a subcomponent with a RichHandler""" # """Creates a logger for a subcomponent with a RichHandler"""
component = type(self).__name__ # component = type(self).__name__
parent = self.args['app'] # parent = self.args['app']
cfg_dict = component_logging_config(parent_room=parent, component=component) # cfg_dict = component_logging_config(parent_room=parent, component=component)
logger_name = next(iter(cfg_dict['loggers'])) # logger_name = next(iter(cfg_dict['loggers']))
try: # try:
logging.config.dictConfig(cfg_dict) # logging.config.dictConfig(cfg_dict)
except Exception: # except Exception:
console.print_exception() # console.print_exception()
else: # else:
logger = logging.getLogger(logger_name) # logger = logging.getLogger(logger_name)
logger = logging.LoggerAdapter(logger, {'room': parent, 'component': component}) # logger = logging.LoggerAdapter(logger, {'room': parent, 'component': component})
return logger # return logger

View File

@@ -1,18 +1,21 @@
from logging import Logger from logging import Logger
from typing import TYPE_CHECKING
from appdaemon.plugins.hass.hassapi import Hass from appdaemon.plugins.hass.hassapi import Hass
from room_control import RoomController from . import console
from .console import setup_component_logging if TYPE_CHECKING:
from room_control import RoomController
class Door(Hass): class Door(Hass):
app: 'RoomController'
logger: Logger logger: Logger
async def initialize(self): async def initialize(self):
self.logger = setup_component_logging(self) self.app: 'RoomController' = await self.get_app(self.args['app'])
self.app: RoomController = await self.get_app(self.args['app']) self.logger = console.load_rich_config(room=self.app.name, component=type(self).__name__)
self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG') self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG')
await self.listen_state( await self.listen_state(

View File

@@ -47,9 +47,7 @@ class ApplyKwargs(BaseModel):
class ControllerStateConfig(BaseModel): class ControllerStateConfig(BaseModel):
time: Optional[str | datetime] = None time: Optional[str | datetime] = None
elevation: Optional[float] = None elevation: Optional[float] = None
direction: Optional[Annotated[SunDirection, BeforeValidator(str_to_direction)]] = ( direction: Optional[Annotated[SunDirection, BeforeValidator(str_to_direction)]] = None
None
)
off_duration: Optional[OffDuration] = None off_duration: Optional[OffDuration] = None
scene: dict[str, State] | str scene: dict[str, State] | str
@@ -57,13 +55,9 @@ class ControllerStateConfig(BaseModel):
def check_args(cls, values): def check_args(cls, values):
time, elevation = values.get('time'), values.get('elevation') time, elevation = values.get('time'), values.get('elevation')
if time is not None and elevation is not None: if time is not None and elevation is not None:
raise PydanticCustomError( raise PydanticCustomError('bad_time_spec', 'Only one of time or elevation can be set.')
'bad_time_spec', 'Only one of time or elevation can be set.'
)
elif elevation is not None and 'direction' not in values: elif elevation is not None and 'direction' not in values:
raise PydanticCustomError( raise PydanticCustomError('no_sun_dir', 'Needs sun direction with elevation')
'no_sun_dir', 'Needs sun direction with elevation'
)
return values return values
def to_apply_kwargs(self, **kwargs): def to_apply_kwargs(self, **kwargs):
@@ -85,9 +79,7 @@ class RoomControllerConfig(BaseModel):
if app_cfg['class'] == 'RoomController': if app_cfg['class'] == 'RoomController':
return cls.model_validate(app_cfg) return cls.model_validate(app_cfg)
def __rich_console__( def __rich_console__(self, console: Console, options: ConsoleOptions) -> RenderResult:
self, console: Console, options: ConsoleOptions
) -> RenderResult:
table = Table( table = Table(
Column('Time', width=15), Column('Time', width=15),
Column('Scene'), Column('Scene'),

View File

@@ -5,9 +5,9 @@ from typing import TYPE_CHECKING, Literal, Optional
from appdaemon.entity import Entity from appdaemon.entity import Entity
from appdaemon.plugins.hass.hassapi import Hass from appdaemon.plugins.hass.hassapi import Hass
from pydantic import BaseModel, TypeAdapter from pydantic import BaseModel, ValidationError
from .console import setup_component_logging from . import console
if TYPE_CHECKING: if TYPE_CHECKING:
from room_control import RoomController from room_control import RoomController
@@ -52,9 +52,8 @@ class Motion(Hass):
return self.sensor_state != self.ref_entity_state return self.sensor_state != self.ref_entity_state
def initialize(self): def initialize(self):
self.logger = setup_component_logging(self)
self.app: 'RoomController' = self.get_app(self.args['app']) self.app: 'RoomController' = self.get_app(self.args['app'])
self.log(f'Connected to AD app [room]{self.app.name}[/]', level='DEBUG') self.logger = console.load_rich_config(self.app.name, type(self).__name__)
assert self.entity_exists(self.args['sensor']) assert self.entity_exists(self.args['sensor'])
assert self.entity_exists(self.args['ref_entity']) assert self.entity_exists(self.args['ref_entity'])
@@ -66,14 +65,11 @@ class Motion(Hass):
if self.state_mismatch: if self.state_mismatch:
self.log( self.log(
f'Sensor is {self.sensor_state} ' f'Sensor is {self.sensor_state} ' f'and light is {self.ref_entity_state}',
f'and light is {self.ref_entity_state}',
level='WARNING', level='WARNING',
) )
if self.sensor_state: if self.sensor_state:
self.app.activate( self.app.activate(kwargs={'cause': f'Syncing state with {self.sensor.entity_id}'})
kwargs={'cause': f'Syncing state with {self.sensor.entity_id}'}
)
# don't need to await these because they'll already get turned into a task by the utils.sync_wrapper decorator # don't need to await these because they'll already get turned into a task by the utils.sync_wrapper decorator
self.listen_state( self.listen_state(
@@ -83,16 +79,20 @@ class Motion(Hass):
) )
self.listen_state(**base_kwargs, new='off', callback=self.callback_light_off) self.listen_state(**base_kwargs, new='off', callback=self.callback_light_off)
if callbacks := self.callbacks(): for handle, cb in self.callbacks():
for handle, entry in callbacks.items(): self.log(f'Handle [yellow]{handle[:4]}[/]: {cb.function}', level='DEBUG')
self.log(
f'Handle [yellow]{handle[:4]}[/]: {entry.function}', level='DEBUG' self.log(f'Initialized [bold green]{type(self).__name__}[/]')
)
def callbacks(self): def callbacks(self):
"""Returns a dictionary of validated CallbackEntry objects that are associated with this app""" """Returns a dictionary of validated CallbackEntry objects that are associated with this app"""
data = TypeAdapter(Callbacks).validate_python(self.get_callback_entries()) self_callbacks = self.get_callback_entries().get(self.name, {})
return data.get(self.name, {}) for handle, cb_dict in self_callbacks.items():
try:
yield handle, CallbackEntry.model_validate(cb_dict)
except ValidationError as e:
self.logger.error('Error parsing callback dictionary')
self.logger.error(e)
def listen_motion_on(self): def listen_motion_on(self):
"""Sets up the motion on callback to activate the room""" """Sets up the motion on callback to activate the room"""
@@ -104,9 +104,7 @@ class Motion(Hass):
oneshot=True, oneshot=True,
cause='motion on', cause='motion on',
) )
self.log( self.log(f'Waiting for sensor motion on [friendly_name]{self.sensor.friendly_name}[/]')
f'Waiting for sensor motion on [friendly_name]{self.sensor.friendly_name}[/]'
)
if self.sensor_state: if self.sensor_state:
self.log( self.log(
f'Sensor [friendly_name]{self.sensor.friendly_name}[/] is already on', f'Sensor [friendly_name]{self.sensor.friendly_name}[/] is already on',
@@ -134,18 +132,14 @@ class Motion(Hass):
level='WARNING', level='WARNING',
) )
def callback_light_on( def callback_light_on(self, entity=None, attribute=None, old=None, new=None, kwargs=None):
self, entity=None, attribute=None, old=None, new=None, kwargs=None
):
"""Called when the light turns on""" """Called when the light turns on"""
if new is not None: if new is not None:
self.log(f'Detected {entity} turning on', level='DEBUG') self.log(f'Detected {entity} turning on', level='DEBUG')
duration = self.app.off_duration() duration = self.app.off_duration()
self.listen_motion_off(duration) self.listen_motion_off(duration)
def callback_light_off( def callback_light_off(self, entity=None, attribute=None, old=None, new=None, kwargs=None):
self, entity=None, attribute=None, old=None, new=None, kwargs=None
):
"""Called when the light turns off""" """Called when the light turns off"""
self.log(f'Detected {entity} turning off', level='DEBUG') self.log(f'Detected {entity} turning off', level='DEBUG')
self.listen_motion_on() self.listen_motion_on()

View File

@@ -1,4 +1,5 @@
import datetime import datetime
import json
import logging import logging
import logging.config import logging.config
from copy import deepcopy from copy import deepcopy
@@ -8,7 +9,7 @@ from appdaemon.entity import Entity
from appdaemon.plugins.hass.hassapi import Hass from appdaemon.plugins.hass.hassapi import Hass
from appdaemon.plugins.mqtt.mqttapi import Mqtt from appdaemon.plugins.mqtt.mqttapi import Mqtt
from .console import console, room_logging_config from . import console
from .model import ControllerStateConfig, RoomControllerConfig from .model import ControllerStateConfig, RoomControllerConfig
logger = logging.getLogger(__name__) logger = logging.getLogger(__name__)
@@ -33,14 +34,8 @@ class RoomController(Hass, Mqtt):
assert all(isinstance(s, ControllerStateConfig) for s in new), f'Invalid: {new}' assert all(isinstance(s, ControllerStateConfig) for s in new), f'Invalid: {new}'
self._room_config.states = new self._room_config.states = new
def configure_logging(self) -> dict:
logging.config.dictConfig(room_logging_config(self.name))
self.logger = logging.LoggerAdapter(
logging.getLogger(f'AppDaemon.{self.name}'), {'room': self.name}
)
def initialize(self): def initialize(self):
self.configure_logging() self.logger = console.load_rich_config(self.name)
self.app_entities = self.gather_app_entities() self.app_entities = self.gather_app_entities()
# self.log(f'entities: {self.app_entities}') # self.log(f'entities: {self.app_entities}')
self.refresh_state_times() self.refresh_state_times()
@@ -95,10 +90,6 @@ class RoomController(Hass, Mqtt):
assert isinstance(state.time, datetime.time), f'Invalid time: {state.time}' assert isinstance(state.time, datetime.time), f'Invalid time: {state.time}'
# if self.logger.isEnabledFor(logging.DEBUG):
# # table = self._room_config.rich_table(self.name)
# console.print(self._room_config)
self.states = sorted(self.states, key=lambda s: s.time, reverse=True) self.states = sorted(self.states, key=lambda s: s.time, reverse=True)
# schedule the transitions # schedule the transitions
@@ -209,9 +200,7 @@ class RoomController(Hass, Mqtt):
elif isinstance(scene_kwargs, dict): elif isinstance(scene_kwargs, dict):
self.call_service('scene/apply', **scene_kwargs) self.call_service('scene/apply', **scene_kwargs)
if self.logger.isEnabledFor(logging.INFO): self.log(f'Applied scene:\n{json.dumps(scene_kwargs, indent=2)}', level='DEBUG')
self.log('Applied scene:')
console.print(scene_kwargs['entities'])
elif scene_kwargs is None: elif scene_kwargs is None:
self.log('No scene, ignoring...') self.log('No scene, ignoring...')