59. Logging¶

Logging in SolarNode is configured in the /etc/solarnode/log4j2.xml file, which is in the log4j configuration format. The default configuration in SolarNodeOS sets the overall verbosity to INFO and logs to a temporary storage area /run/solarnode/log/solarnode.log.

59.1 Logging concepts¶

Log messages have the following general properties:

59.2 Logger namespaces¶

The Logger component outlined in the previous section allows a lot of flexibility to configure what gets logged in SolarNode. Setting the level on a given namespace impacts that namespace as well as all namespaces beneath it, meaning all other loggers that share the same namespace prefix.

For example, imagine the following two loggers exist in SolarNode:

• net.solarnetwork.node.io.modbus.serial.SerialModbusNetwork
• net.solarnetwork.node.io.modbus.util.ModbusUtils

Given the default configuration sets the default level to INFO, we can turn in DEBUG logging for both of these by adding a <Logger> line like the following within the <Loggers> element:

<Logger name="net.solarnetwork.node.io.modbus" level="debug"/>

That turns on DEBUG for both loggers because they are both children of the net.solarnetwork.node.io.modbus namespace. We could turn on TRACE logging for one of them like this:

<Logger name="net.solarnetwork.node.io.modbus"        level="debug"/>
<Logger name="net.solarnetwork.node.io.modbus.serial" level="trace"/>

That would also turn on TRACE for any other loggers in the net.solarnetwork.node.io.modbus.serial namespace. You can limit the configuration all the way down to a full logger name if you like, for example:

<Logger name="net.solarnetwork.node.io.modbus"                            level="debug"/>
<Logger name="net.solarnetwork.node.io.modbus.serial.SerialModbusNetwork" level="trace"/>

59.3 Logging UI¶

The SolarNode UI supports configuring logger levels dynamically, without having to change the logging configuration file. See the Setup App / Settings / Logging page for more information.

59.4 Storage constraints¶

The default SolarNode configuration automatically rotates log files based on size, and limits the number of historic log files kept around, to that its associated storage space is not filled up. When a log file reaches the file limit, it is renamed to include a -i.log suffix, where i is an offset from the current log. The default configuration sets the maximum log size to 1 MB and limits the number of historic files to 3.

You can also adjust how much history is saved by tweaking the <SizeBasedTriggeringPolicy> and <DefaultRolloverStrategy> configuration. For example to change to a limit of 9 historic files of at most 5 MB each, the configuration would look like this:

<Policies>
  <SizeBasedTriggeringPolicy size="5 MB"/>
</Policies>
<DefaultRolloverStrategy max="9"/>

59.5 Persistent logging¶

By default SolarNode logs to temporary (RAM) storage that is discarded when the node reboots. The configuration can be changed so that logs are written directly to persistent storage if you would like to have the logs persisted across reboots, or would like to preserve more log history than can be stored in the temporary storage area.

To make this change, update the <RollingFile> element's fileName and/or filePattern attributes to point to a persistent filesystem. SolarNode already has write permission to the /var/lib/solarnode/var directory, so an easy location to use is /var/lib/solarnode/var/log, like this:

<RollingFile name="File"
    immediateFlush="false"
    fileName="/var/lib/solarnode/var/log/solarnode.log"
    filePattern="/var/lib/solarnode/var/log/solarnode-%i.log">

59.6 Logging example: split across multiple files¶

Sometimes it can be useful to turn on verbose logging for some area of SolarNode, but have those messages go to a different file so they don't clog up the main solarnode.log file. This can be done by configuring additional appender configurations.

The following example logging configuration creates the following log files:

• /var/log/solarnode/solarnode.log - the main log
• /var/log/solarnode/filter.log - filter logging
• /var/log/solarnode/mqtt-solarin.log - MQTT wire logging to SolarIn
• /var/log/solarnode/mqtt-solarflux.log - MQTT wire logging to SolarFlux

First you must create the /var/log/solarnode directory and give SolarNode permission to write there:

sudo mkdir /var/log/solarnode
sudo chgrp solar /var/log/solarnode
sudo chmod g+w /var/log/solarnode

Then edit the /etc/solarnode/log4j2.xml file to hold the following (adjust according to your needs):

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <RollingFile name="File"
        immediateFlush="true"
        fileName="/var/log/solarnode/solarnode.log"
        filePattern="/var/log/solarnode/solarnode-%i.log"><!-- (1)! -->
      <PatternLayout pattern="%d{DEFAULT} %-5p %40.40c; %msg%n"/>
      <Policies>
        <SizeBasedTriggeringPolicy size="5 MB"/>
      </Policies>
      <DefaultRolloverStrategy max="9"/>
    </RollingFile>
    <RollingFile name="Filter"
        immediateFlush="false"
        fileName="/var/log/solarnode/filter.log"
        filePattern="/var/log/solarnode/filter-%i.log"><!-- (2)! -->
      <PatternLayout pattern="%d{DEFAULT} %-5p %40.40c; %msg%n"/>
      <Policies>
        <SizeBasedTriggeringPolicy size="10 MB"/>
      </Policies>
      <DefaultRolloverStrategy max="9"/>
    </RollingFile>
    <RollingFile name="MQTT"
        immediateFlush="false"
        fileName="/var/log/solarnode/mqtt.log"
        filePattern="/var/log/solarnode/mqtt-%i.log"><!-- (3)! -->
      <PatternLayout pattern="%d{DEFAULT} %-5p %40.40c; %msg%n"/>
      <Policies>
        <SizeBasedTriggeringPolicy size="10 MB"/>
      </Policies>
      <DefaultRolloverStrategy max="9"/>
    </RollingFile>
    <RollingFile name="Flux"
        immediateFlush="false"
        fileName="/var/log/solarnode/flux.log"
        filePattern="/var/log/solarnode/flux-%i.log"><!-- (4)! -->
      <PatternLayout pattern="%d{DEFAULT} %-5p %40.40c; %msg%n"/>
      <Policies>
        <SizeBasedTriggeringPolicy size="10 MB"/>
      </Policies>
      <DefaultRolloverStrategy max="9"/>
    </RollingFile>
  </Appenders>
  <Loggers>
    <Logger name="org.eclipse.gemini.blueprint.blueprint.container.support" level="warn"/>
    <Logger name="org.eclipse.gemini.blueprint.context.support" level="warn"/>
    <Logger name="org.eclipse.gemini.blueprint.service.importer.support" level="warn"/>
    <Logger name="org.springframework.beans.factory" level="warn"/>

    <Logger name="net.solarnetwork.node.datum.filter" level="trace" additivity="false">
      <AppenderRef ref="Filter"/><!-- (5)! -->
    </Logger>

    <Logger name="net.solarnetwork.mqtt.queue" level="trace" additivity="false">
      <AppenderRef ref="MQTT"/>
    </Logger>

    <Logger name="net.solarnetwork.mqtt.influx" level="trace" additivity="false">
      <AppenderRef ref="Flux"/>
    </Logger>

    <Root level="info">
      <AppenderRef ref="File"/><!-- (6)! -->
    </Root>
  </Loggers>
</Configuration>

1. The File appender is the "main" application log where most logs should go.
2. The Filter appender is where we want net.solarnetwork.node.datum.filter messages to go.
3. The MQTT appender is where we want net.solarnetwork.mqtt.queue messages to go.
4. The Flux appender is where we want net.solarnetwork.mqtt.influx messages to go.
5. Here we include additivity="false" and add the <AppenderRef> element that refereneces the specific appender name we want the log messages to go to. The additivity=false attribute means the log messages will only go to the Filter appender, instead of also going to the root-level File appender.
6. The root-level appender is the "default" destination for log messages, unless overridden by a specific appender like we did for the Filter, MQTT, and Flux appenders above.

59.6.1 Separate file configuration notes¶

The various <AppenderRef> elements configure the appender name to write the messages to.

The various additivity="false" attributes disable appender additivity which means the log message will only be written to one appender, instead of being written to all configured appenders in the hierarchy (for example the root-level appender).

The immediateFlush="false" turns on buffered logging, which means log messages are buffered in RAM before being flushed to disk. This is more forgiving to the disk, at the expense of a delay before the messages appear.

59.7 Enable MQTT wire logging¶

MQTT wire logging means the raw MQTT packets send and received over MQTT connections will be logged in an easy-to-read but very verbose format. For the MQTT wire logging to be enabled, it must be activated with a special configuration file. Create the /etc/solarnode/services/net.solarnetwork.common.mqtt.netty.cfg file with this content:

wireLogging = true

59.7.1 MQTT wire log namespace¶

MQTT wire logs use a namespace prefix net.solarnetwork.mqtt. followed by the connection's host name or IP address and port. For example SolarIn messages would use net.solarnetwork.mqtt.queue.solarnetwork.net:8883 and SolarFlux messages would use net.solarnetwork.mqtt.influx.solarnetwork.net:8884.