Logging QOL

[Dantenz]

Thanks for HABApp - I've avoided automation on OpenHAB for years because the options aren't great, and now I'm finally able to build a solid automation suite using modern tooling.

One of the small things I've ran into was regarding logging. It seems that HABApp offers you the option of configuring your loggers in the logging.yml file. This is great for simpler use cases, but most of my rules are dynamically generated (I have a few classes that are instantiated for x number of rooms).

So if I use a logger named CustomRules, I get the following for all classes and all instances: [ CustomRules] INFO | Some logging text

Ideally what I'd like is to be able to rename that logger name on the fly, so I have something like: [ Lighting - Dining] INFO | Some logging text [ Lighting - Kitchen] INFO | Some other logging text

I've spent hours trying to intercept the logging instance and force it into submission, but I gave up. One of the issues was that the class names are instantiated with a sequential number (e.g. Lighting1). I think the only alternative is to use my own logging framework, which seems overkill. My temporary solution is not great - I basically add a customised string onto the beginning of every log entry.

logger.info(f"{class} - {room}: Some logging text")
#[       CustomRules]     INFO | Lighting - Dining: Some logging text

Ideal solution would be:

1. Allow to rename dynamically instantiated class
2. Create new logger on the fly based on template in the logging.yml file, named after dynamically instantiated class

Thanks

[magnuslsjoberg]

I may misunderstand your comment about class name, but if your classes are HABApp rules, you can use 'self.rule_name' to set your own name, e.g:

class SensorModel(HABApp.Rule):
    def __init__( self, name:str, sensor_type:str ):
        super().__init__()
        self.rule_name  = f'Sensor_{name}'

[Dantenz]

Thanks, that helps but is there a way of getting that rule name to output automatically as part of the log entry?

[magnuslsjoberg]

You could create a logger for each object/rule:

class SensorModel(HABApp.Rule):
    def __init__( self, name:str, sensor_type:str ):
        super().__init__()
        self.rule_name  = f'Sensor_{name}'
        self.log = logging.getLogger(self.rule_name)
        self.log.info('message')

[Dantenz]

Ok, this would side-step the logging.yml and require me to set up my own handlers, etc. This is what I wanted to avoid, but if it's the only way then I'll deal with it. Thanks

[magnuslsjoberg]

It may be much better ways to handle this, but this handles my needs.

BTW: You don't need to add these in logging.yml!!! I only have these 2 formatters:

formatters:
  HABApp_format:
    format: '[%(asctime)s] [%(name)25s] %(levelname)8s | %(message)s'

  Frontail_format:
    format: '%(asctime)s.%(msecs)03d [%(levelname)-5s] [%(name)-36s] - %(message)s'
    datefmt: '%Y-%m-%d %H:%M:%S'

And it seems like "name" must contain "HABApp.name" (at least in my setup)

[Dantenz]

Seems like the main benefit of using the existing logging framework is that is sets up the rotating file handlers, different streams, etc.

I'd like exactly the same functionality, but only to rename the logger to the self.rule_name.

Update: I managed to get it working how I wanted:

Logging.yml

loggers:
  CustomRules:
    level: DEBUG
    handlers:
      - HABApp_default
      - StdOutHandler
    propagate: True

Code

        self.logger = logging.getLogger(self.rule_name)

        handlers = logging.getLogger('CustomRules').handlers
        for h in handlers:
            self.logger.addHandler(h)

        self.logger.setLevel('DEBUG')

It's basically copying the settings defined in the logging.yml and placing into a new logger named after the renamed rule.

I'm not even sure it's worth requesting HABApp to be changed to support this - it's quite easy, but not not super intuitive if you're new.

[spacemanspiff2007]

class SensorModel(HABApp.Rule):
    def __init__( self, name:str, sensor_type:str ):
        super().__init__()
        self.rule_name  = f'Sensor_{name}'
        self.log = logging.getLogger(self.rule_name)
        self.log.info('message')

Thanks @magnuslsjoberg - this is the solution. Just create a logger in each rule and reference the logger name in the logging.yml

Ok, this would side-step the logging.yml and require me to set up my own handlers, etc. This is what I wanted to avoid, but if it's the only way then I'll deal with it. Thanks

No - your misunderstanding how everything works. In the logging.yml you can define

• loggers
• attach handlers to the defined loggers and dynamically change the logging configuration during runtime.

In the code you just reference the logger by name with logging.getLogger

In your case it should be

logging.getLogger('Lighting.Kitchen')
logging.getLogger('Lighting.Dining')

and one logger named Lighting should be defined in the logging.yml. If there is no logger Lighting it'll automatically use the current root logger.

If you read up a little bit about the logging library of the standard installation it'll start to make sense.

[Dantenz]

Yes I've totally misunderstood - I see it in the docs.

Makes sense, thanks.