I am looking for inspiration for how to setup logging and the logging-structure within HABapp. How are you doing it?
My initial attempt was done at a point where I did not really understand the “python-logging”-structure. I have come to a point where I want to rebuild this.
Requirements:
Production: I want to know if everything is running as it should.
Development/debugging: Extensive debug-messages for individual parts/rules, which can be one instance or generic (all instances) of a specific Rule.
When/Where/What?
When/time and what is handled by the framework and the logging message. But where?? In what module/context did the message fire? In some cases I am using Rules instanced inside other rules.
Can I get the context from within the logging-framework?
How can I set individual parts/Rules into DEBUG-mode? For an instance or for generic usage? (my first attempt was to have a debug:bool variable set in the constructor, changing a local logger.debug(msg) into a logger.info(msg), but Im sure there are better ways)
Handlers/Loggers-setup
In my first attempt I had RuleLog and DeviceLog. DeviceLog for every message where a Rule was used as instance by another Rule (example: a shelly-dimmer or an occupancy-sensor). And RuleLog for the top-layer (example: light control in office). What structure of handlers/loggers do you have?
Sometimes I have a per module logger, sometimes a rule instance specific logger.
I get them with log = logging.getLogger('name') . With dots you can modle a structure, e.g. log = logging.getLogger('parent.child') which I use when I do per rule instance loggers.
In the logging.yml you than can set the name of the logger (e.g. only the parent or the complete name). There you can also change the level which will be reloaded on the fly. That means you can change the logging without having to start/stop the rules.
I grouped the loggers logically in files (e.g. by room or generic like forecasts) so I know where to look.
Im still experimenting different setups and especially a way to find the “context” of a log-message, ie from which rule is the log-message deriving?
One way I found is to insert self.rule_name into the log-message, this is possible, but still a bit clumsy.
logger.info(f'{self.rule_name} {msg}')
I also tested a more generic way with logging.LoggerAdopter which can add ‘fields’ that can be parsed by the logging-formater.
logger = logging.getLogger('my_log')
class MyRule(Rule):
def __init__(self, my_rule_name = None)
if my_rule_name is not None:
self.rule_name = my_rule_name
global logger
logger = logging.LoggerAdapter(logger, {'rule_name' : self.rule_name})
formatters:format: '[%(rule_name)s]'
With the drawbacks that the LoggerAdapter-call must be done inside the rule to get the name? And also if i try to apply a %rule_name-format for a msg where this was not originally attached will create an exception.
This is a similar ‘safer’ setup, avoiding the risk of such exception.
logger : logging.Logger
class MyRule(Rule):
def __init__(self, my_rule_name = None)
if my_rule_name is not None:
self.rule_name = my_rule_name
global logger
logger = logging.getLogger(f'my_log.{self.rule_name}')
Am I missing something obvious? Are there other possibilities?
logger = logging.getLogger('my_log')
class MyRule(Rule):
def __init__(self, my_rule_name)
self.log = logger.getChild(my_rule_name) # this is the same as logging.getLogger(f'my_log.{my_rule_name:s}') but in a more practical way
self.log.info('Hello from the rule logger')
