Skip to content

Log Messages

Erik Baauw edited this page Sep 24, 2022 · 5 revisions

Log Messages

This page describes how Homebridge Lib deals with log messages.

Severity

Homebridge Lib supports log messages of different levels of severity:

Severity Description
fatal Indicates an unrecoverable problem, causing the programme to exit.
error Indicates a problem that needs to be resolved. The programme can still continue, but with limited functionality.
warning Indicates a problem that might be ignored. The programme continues normally.
info Provides information, used for understanding what the programme is doing.
Typically, this level is used to log the interaction with HomeKit: when characteristic values are changed from HomeKit, or when the plugin changes characteristic values, to reflect a change in the device state.
debug Provides technical information, used for analysing issues.
Typically, this level is used to log the interaction with the (bridge or gateway exposing the) device.
vdebug Provides detailed technical information, used for analysing issues.
Typically, this level is used to log the full interaction with the device, including the url and request body. Note that this might include sensitive information, like API tokens.
vvdebug Provides very detailed technical information, used for analysing issues.
This level is used by Homebridge ZP to log the SOAP over HTTP calls and XML bodies when interacting with a Sonos zone player.

End users need to see fatal, error, and warning messages. Novice end users might want to monitor info messages, to learn how the plugin works, but experienced end users tend to get annoyed by these. debug, verbose debug, and very verbose debug messages are vital for analysing issues, but tend to fill up log files rather quickly. Basically these should be issued only when experiencing issues.

Current Log Level

To address the different needs for log messages, Homebridge Lib supports the notion of a current log level, a number between 0 and 4, which indicates whether to issue or to suppress log messages of a certain severity.

Severity Logged When
fatal Always.
error Always.
warning Always.
info The current log level is at least 1.
debug Homebridge is running in debug mode and the current log level is at least 2.
vdebug Homebridge is running in debug mode and the current log level is at least 3.
vvdebug Homebridge is running in debug mode and the current log level is 4.

To run Homebridge is debug mode, use the Homebridge UI to set the Homebridge Debug Mode -D under Startup Options in the Homebridge Settings window.
When starting Homebridge manually, run homebridge -D.

Dynamic Log Level

When running Homebridge with multiple plugins, or when exposing multiple devices from a single plugin, you typically don't want the log file to fill up with debug messages and turn off logging. However, when you experience an issue, you want to enable debug log messages for the corresponding plugin or device, while not being bothered by debug messages from other devices or plugins. Also, you want to be able to enable or disable these debug log messages dynamically, without having to restart Homebridge.

To address this, Homebridge Lib supports a log level per plugin, or even per accessory. This log level can be controlled from HomeKit, using the (custom) Log Level characteristic. As this is a custom characteristic, Apple's Home app doesn't support it. To use it, you'll need another HomeKit app, like Eve.

The default Log Level value is 2, but once changed, the new value is persisted across Homebridge restarts.

For command line tools, the default log level is 0. It can be changed by specifying -v or --verbose (for level 1) or -D or --debug for level 2. Multiple -D arguments can be combined for more verbose debug levels, e.g. -DDD for level 4.

The log level can be maintained through the logLevel property of AccessoryDelegate and Platform. The accessory can also be setup to inherit the log level from the associated plugin. MyHomeKitTypes defines a LogLevel characteristic, which can be used to change the log level from within HomeKit.

Implementation

This section lists the technical implementation for developers of plugins based on Homebridge Lib.

Log Level

MyHomeKitTypes defines the LogLevel characteristic. By default, the maximum value is 3. To change that, pass props: { maxValue: 4 } to addCharacteristicDelegate().

Each Delegate instance has a logLevel property, which is fixed to 2. CharacteristicDelegate and ServiceDelegate override this property, returning the logLevel value of the associated AccessoryDelegate instead. AccessoryDelegate overrides this property, returning the logLevel value of the associated Platform.

To manage the log level from HomeKit, include a CharacteristicDelegete for the LogLevel characteristic in one of its ServiceDelegate children.

    this.addCharacteristicDelegate({
      key: 'logLevel',
      Characteristic: this.Characteristics.my.LogLevel,
      value: this.accessoryDelegate.logLevel
    })

Next, call AccessoryDelegate.manageLogLevel() to re-define logLevel to return the value of the CharacteristicDelegate instead.

    this.manageLogLevel(this.service.characteristicDelegate('logLevel'))

To inherit the log level from another accessory, use AccessoryDelegate.inheritLogLevel().

For plugins that don't have separate API calls for different accessories, like Homebridge OTGW, Homebridge P1, or Homebridge WS, the logLevel can be maintained at the platform level.

    this.manageLogLevel(this.service.characteristicDelegate('logLevel'), true)

Note that only the first AccessoryDelegate to call this gets to maintain the Platform log level.

Delegate and Subclasses

Platform, AccessoryDelegate, ServiceDelegate, and CharacteristicDelegate provide the following methods to log messages:

Method Level Output Colour Description
fatal() 0 stderr red Writes an error message (in red) to the standard error output, and exits the programme.
error() 0 stderr red Writes an error message (in red) to the standard error output.
warn() 0 stderr yellow Writes a warning message (in red) to the standard error output.
log() 1 stdout none Writes an information message to the standard output, when logLevel is at least 1.
debug() 2 stdout grey Writes a debug message (in grey) to the standard output, when logLevel is at least 2, and Homebridge debug mode has been enabled.
vdebug() 3 stdout grey Writes a verbose debug message (in grey) to the standard output. when logLevel is at least 3, and Homebridge debug mode has been enabled.
vvdebug() 4 stdout grey Writes a verbose debug message (in grey) to the standard output. when logLevel is at least 3, and Homebridge debug mode has been enabled.

For ServiceDelegate and CharacteristicDelegate, Homebridge Lib prepends the message with the service name. For AccessoryDelegate, Homebridge Lib prepends the message with the accessory name. Homebridge Lib uses Homebridge's standard log() function to issue the messages. Homebridge prepends the message with a timestamp, and the plugin name.

CommandLineTool

An instance of CommandLineTool is regular programme, that might be invoked from the command line, or run in the background as a service.

By default, a CommandLineTool instance runs at log level 1. This might be changed on startup, typically by passing a command-line parameter -D or --debug for log level 2, -DD or --debug --debug for log level 3, or -DDD or --debug --debug --debug for log level 4.

CommandLineTool provides the following methods for log messages:

Method Level Output Colour Description
print() 0 stdout none Writes an output message to the standard output.
fatal() 0 stderr red Writes an error message (in red) to the standard error output, and exits the programme.
error() 0 stderr red Writes an error message (in red) to the standard error output.
warn() 0 stderr yellow Writes a warning message (in red) to the standard error output.
log() 1 stderr none Writes an information message to the standard error output, when logLevel is at least 1.
debug() 2 stderr grey Writes a debug message (in grey) to the standard error output, when logLevel is at least 2.
vdebug() 3 stderr grey Writes a verbose debug message (in grey) to the standard error output. when logLevel is at least 3.
vvdebug() 4 stderr grey Writes a verbose debug message (in grey) to the standard error output. when logLevel is 4.

For regular output of the programme, use print(). This method writes the message to the standard output, which might be piped to another programme. All other methods write to the standard error output, so their messages might be separated from the standard output.

Note that the colours are used only when mode is daemon or service. Depending on the mode, messages to the standard error output might be preceded by a timestamp and by the programme name.

Mode Colours Programme Timestamp Intended Usage
command No Yes No When run from the command line.
daemon Yes No Yes When run in the background, with output re-directed to a dedicated log file.
service Yes No No When run as a service, with output re-directed to syslog.