Best practice for logging in rules

Hi there,

ist there any best practice for logging in rules? In my understanding openHAB offers four levels of logging with appropriate functions:

Error
logError - Log an error that occurred during the execution of a rule. This might be a catched exception. Main idea is that the rule cannot finish successfully.

Warning
logWarn - Log a warning that something is wrong, but can be fixed by the programming of the rule. That is maybe that a NULL value is replaced by a default value.

Information
logInfo - Log a simple information about something that might be interesting to the user in the log if the system works under normal condition. This might be the information that a specific state is reached or something has happend.

Debugging
logDebug - Log an information that is as much helpfull in the case of debugging. This covers everything from simple checkmarks up to detailed information about variables etc.

If this is a more or less common understanding the next question is when to include which kind of logging in a rule.

Error

  1. Report every exception caught as a logError

Warn

  1. Report every used default value as a LogWarn
  2. Report every not expected NULL value as a logWarn

Information

  1. Add an info log entry every time required to show that normal operation is performed.

Debug

  1. Enclose every functional block in a rules with logDebug. One for the entry with a short description and values that are transported into the functional block. A log entry second if the functional block is finished with the values that are produced by the block

I have not used this scheme in my rules so far, so please feel free to add you best practice.

Thomas

1 Like

Logging is very context dependent. What does the Rule do? How much of a problem is it if the Rule fails to run or is unable to run?

The severity of the log should reflect the import of the Rule. For example, if I have an exception or problem in my Rule that processes the weather forecast, I might use just a WARN level log because nothing else in my home automation cares about the forecast; I just get it for my sitemap. However, if an exception or problem occurs in my Rule that processes the current conditions occurs, I’d log that as an ERROR and potentially generate an alert because my HVAC control depends in part on the current weather conditions. Same problem, two different contexts, two different logging levels.

As for INFO versus DEBUG, I tend to use logInfo to log out the sorts of things I want to have in my logs that let me monitor and understand when the home automation is doing something. For example, when the Time of Day setting changed, the presence state changed, when lights are turned ON/OFF automatically, when the garage doors are triggered, when the hvac settings change, etc.

When I’m debugging a problem, I’ll still use INFO for those log statements but when I’m done I will delete those log statements that are no longer useful and convert those that might be useful in the future into a DEBUG.

This approach works for me.

2 Likes

I totally agree that the log level should be based on the context. I will keep that in mind while develoing “my” logging system.

and i am glad to hear that you use the info level while debigging and then throw the infos away or convert them to a debug log (i like that idea)

Thanks
Thomas

1 Like