Logging

Overview

When running, by default Reactor logs most messages to the reactor.log file in the Reactor installation directory, and to the console. The exact name of the log file and level of logging are determined by settings in config/logging.yaml.

The default log level sets the log level for all subsystems in Reactor when logging.yaml does not otherwise have a more specific rule. Do not change the default log level unless instructed to do so by the devs!

To help focus logging on specific subsystems or objects, the logging configuration allows you to add a subsystem/class name and a specific logging level. Here's an example logging.yaml file:

config/logging.yaml

logging:
  default:
    level: 4
  # other data not shown for brevity

  Rule:
    level: 6
  Engine:
    level: 5
  VeraController:
    level: 4
  "HassController#rpi":
    level: 7
  "Entity#hass>switch_zooz_zen15_power_switch_switch":
    level: 8

In the above example, the Engine and Rule subsystems are set to log at levels 5 and 6 respectively. The HomeAssistant controller instance (of class HassController) with ID "rpi" is set to level 7. The specific entity with ID hass>switch_zooz_zen15_power_switch_switch will log at level 8. The ability to set log levels with this kind of granularity is vital for producing usable logs during troubleshooting.

Warning

Notice that the last two entries in the configuration above are in quotes. They contain non-alphanumeric characters, so they must be in quotes.

If you are asked to turn on logging for a particular subsystem as part of troubleshooting, just add the subsystem/class name given to the end of the list (unless it's already there — don't duplicate) indented two spaces and followed by a colon (:). Then, add another line after with level: indented four spaces (see the example above) and the numeric value for the level required. Don't forget to remove the entry or reduce the level when finished troubleshooting.

Attention

After modifying log levels, you must restart Reactor.

Log Levels

The log levels are currently defined as follows:

Level	Severity ID	Description
0	CRIT	Critical
1	ERR	Error
2	WARN	Warning
3	NOTICE	Notification
4	INFO	Informational
5-9	DEBUGn	Debug levels

When setting a logging level for a logger or stream (see below), all severities at and higher the specified level will be logged (pass the filter). Note that lower numbers are higher severity.

Output Size Warning

Log levels 6-9 will produce a lot of output and are general not recommended to be used in normal operation. The author may ask you to use any of these levels temporarily while helping you troubleshooting a problem, but you should restore the filter to level 4 (or default) when finished with that task.

Other Logging Options

The streams array of the logging sections let you determine which streams receive log messages. By default, only the default section contains a streams section, so that all output from all subsystems is directed to one (or a small number of) log files.

There are two types of streams currently supported: console and file. The console stream logs to the system console (stdout), and may be specified only once. By default, the console stream will log only critical messages (level 0).

The file stream type logs to a file (no surprise). The name key sets the name of the file, and should be a simple filename only, not a pathname.

The level key sets the minimum logging level required for a message to be output to the file (e.g. level 4 would direct information level and more severe, but no debug messages, which are levels 5+).

The maxsize key tells the logger how large the log file may grow before it is rotated. The size can be an integer alone, or an integer followed by K, M, or G for kilobytes, megabytes, and gigabytes, respectively. If no scale is given (that is, a number is given by itself, it is assumed to be in megabytes). You may specify of maxsize of 0 to disable log file rotation, but in that case, log files will grow to fill the disk, so you must manage this yourself.

The maxage key, if specified, tells the logger how often to rotate log files. The value can be an integer alone, or an integer followed by secs, mins, hours, or days (which may be abbreviated to a single character, e.g. 1d or 8h). The log will be rotated on the specified interval, even if nothing has been written to it. The time of rotation is adjusted to an even multiple of the interval; for example, maxage: 1d will cause the log to be rotated daily at midnight local time; maxage: 8h would cause the log to be rotated at midnight, 8:00 am, and 4:00 pm local time.

The keep key tells the logger how many log rotations to keep, including the active log.

The recycle key tells the logger how to handle the log file at Reactor startup/restart. If recycle: true, Reactor will rotate the log file at startup. Otherwise, Reactor will append new messages to the current log until it fills (as determined by maxsize).

The mode key sets the file mode for new log files (using same numeric mode as chmod(1)). The file mode is subject to the process' umask, so specifying a mode of 0o666 does not guarantee that the created file will get 0o666 permissions — if the umask for the process is 0o022, then the log file will be created with 0o644 (you'll have to change the process' umask if you want different behavior, which is OS-dependent and out of scope for this doc).

Octal Permissions

In Linux, permissions on the command line are often given as octal (base 8) values. In order to represent an octal value in YAML configuration, you use the 0o (zero and lowercase letter O) prefix as shown in the text above.

In this example, we set up a separate file for logging all warnings (and worse) to an errors.log file, logging for a specific rule to a file of its own, and logging for ZWaveJSController to another file.

---
logging:
  default:
    level: 4
    streams:
      # Default console log only the most severe messages.
      - type: console
        level: 0
      # This is a typical reactor.log configuration (inherits log level from parent)
      - type: file
        name: "reactor.log"
        maxsize: 8 # megabytes default
        keep: 5 # old logs
        capture_console: true
        recycle: true
      # This logs all errors and more severe to errors.log
      - type: file
        name: "errors.log"
        maxsize: 4096K
        keep: 2
        recycle: true
        level: 2
  # This logs all INFO and more severe messages for a specific rule to rule.log
  "Rule#rule-la04ghp7":
    level: 4
    streams:
      - type: file
        name: rule.log
        maxsize: 8M
        keep: 2
        recycle: true
  # This logs basic debug and up for ZWaveJSController (all instances) to zwavejs.log
  ZWaveJSController:
    level: 5
    streams:
      - type: file
        name: "zwavejs.log"
        maxsize: 8M
        keep: 2
        recycle: true

Note that streams are additive, so even though we have set up a log stream for ZWaveJSController in this example, its messages are still logged to the reactor.log stream in addition to the dedicated log file stream we configured. The logging level for the two streams can be different, however, so as shown, reactor.log will not have debug messages for ZWaveJSController, while zwavejs.log will.

The recycle: true in these examples tells Reactor to start a new log file at restart/reboot. If not specified, an existing log file is appended until it reaches the maxsize limit.

Logging and Entities

Turning up logging on a controller class to try to troubleshoot an entity or attribute problem is useful, but can also cause you to "sip from the firehose": it can dump a lot of information very quickly. If you are going to increase the log level on a Controller class, consider also temporarily configuring the controller to filter out entities that are not the focus of your troubleshooting, to reduce the volume of log data you need to look at.

Posting Log Snippets

If you are asked to post a log snippet, or you do so of your own initiative, please remember the following:

DO redact or mask passwords, API tokens, and other personal or private data you would not want to see made public in your forum post, bug report, PasteBin, etc. If you want to privately email your log file, just PM toggledbits on the forums and I'll give you an address.
DO NOT redact the log data other than to remove or mask passwords, API tokens, and other personal or private data as described above.
DO post at least the twenty lines before and after the part you think is relevant. Most people have trouble identifying what is relevant in the logs (heck, most people don't even bother to look at them, sadly), and you'd be surprised how often people post one line from a log file, leaving out additional detail that explains the error or discloses data that could be used for diagnostics. Don't be "that guy." Context when posting log snippets is vital.
DO let us know what time zone you are in. While there are hourly messages logged that contain this information, if you're posting a snippet and not transferring the whole log, we won't see those, so we need to understand what your local time is relative to the UTC times in the log file.

Updated 04-Oct-2024