-
Notifications
You must be signed in to change notification settings - Fork 2
SolarNode Logging Legacy
⚠️ This page describes the legacy logging configuration used by SolarNode. See the current guide for up-to-date information.
Logging in SolarNode is configured in the /etc/solarnode/log4j.properties file, which is in the
log4j configuration format. The default configuration sets the
overall verbosity to INFO and logs to a temporary storage area /run/solarnode/log/solarnode.log.
Log messages have the following general properties:
| Component | Example | Description |
|---|---|---|
| Timestamp | 2022-03-15 09:05:37 |
The date/time the message was generated. Note the format of the timestamp depends on the logging configuration; the SolarNode default is shown in this example. |
| Level | INFO |
The severity/verbosity of the message (as determined by the developer). This is an enumeration, and from least-to-most severe: TRACE, DEBUG, INFO, WARN, ERROR. The level of a given logger allows messages with that level or higher to be logged, while lower levels are skipped. The default SolarNode configuration sets the overal level to INFO, so TRACE and DEBUG messages are not logged. |
| Logger | ModbusDatumDataSource |
A category or namespace associated with the message. Most commonly these equate to Java class names, but can be any value and is determined by the developer. Periods in the logger name act as a delimiter, forming a hierarchy that can be tuned to log at different levels. For example, given the default INFO level, configuring the net.solarnetwork.node.io.modbus logger to DEBUG would turn on debug-level logging for all loggers in the Modbus IO namespace. Note that the default SolarNode configuration logs just the final logger component (the part after the last . character) which is typically a Java class name. This can be changed in the configuration to log more (or all) of the name, as desired. |
| Message | Error reading from device. |
The message itself, determined by the developer. |
| Exception | Some messages include an exception stack trace, which shows the runtime call tree where the exception occurred. |
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.SerialModbusNetworknet.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 log4j.logger.X line like the following:
log4j.logger.net.solarnetwork.node.io.modbus = 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:
log4j.logger.net.solarnetwork.node.io.modbus = DEBUG
log4j.logger.net.solarnetwork.node.io.modbus.serial = 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:
log4j.logger.net.solarnetwork.node.io.modbus = DEBUG
log4j.logger.net.solarnetwork.node.io.modbus.serial.SerialModbusNetwork = TRACE
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 .0 suffix, after renaming any
existing .0 file to .1, and so on. The default configuration sets the maximum log size to 512
KB and limits the number of historic files to 3.
You can also adjust how much history is saved by tweaking the
log4j.appender.fileAppender.MaxFileSize and log4j.appender.fileAppender.MaxBackupIndex
configuration. For example to change to a limit of 9 historic files of at most 5 MB each,
the configuration would look like this:
log4j.appender.fileAppender.MaxFileSize = 5MB
log4j.appender.fileAppender.MaxBackupIndex = 9
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 log4j.appender.fileAppender.File line 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:
log4j.appender.fileAppender.File = /var/lib/solarnode/var/log/solarnode.log
Note that this configuration adds a lot of stress to the node's storage medium, typically an SD card. Use of this configuration should be used with caution.
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/solarnodeThen edit the /etc/solarnode/log4j.properties file, replacing the fileAppender section at the
end with the following:
log4j.additivity.net.solarnetwork.node.datum.filter = false
log4j.logger.net.solarnetwork.node.datum.filter = INFO, filter
log4j.logger.net.solarnetwork.node.datum.filter.opmode = TRACE
#log4j.logger.net.solarnetwork.node.datum.filter.virt = DEBUG
log4j.additivity.net.solarnetwork.mqtt.queue = false
log4j.logger.net.solarnetwork.mqtt.queue = TRACE, mqtt
log4j.additivity.net.solarnetwork.mqtt.influx = false
log4j.logger.net.solarnetwork.mqtt.influx = TRACE, flux
log4j.appender.fileAppender = org.apache.log4j.RollingFileAppender
log4j.appender.fileAppender.layout = org.apache.log4j.PatternLayout
log4j.appender.fileAppender.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}; %m%n
log4j.appender.fileAppender.File = /var/log/solarnode/solarnode.log
log4j.appender.fileAppender.MaxFileSize = 5MB
log4j.appender.fileAppender.MaxBackupIndex = 9
log4j.appender.fileAppender.BufferedIO = true
#log4j.appender.fileAppender.BufferSize = 64
# NOTE: found that BufferSize is ignored in RollingFileAppender :-(
log4j.appender.filter = org.apache.log4j.RollingFileAppender
log4j.appender.filter.layout = org.apache.log4j.PatternLayout
log4j.appender.filter.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}; %m%n
log4j.appender.filter.File = /var/log/solarnode/filter.log
log4j.appender.filter.MaxFileSize = 10MB
log4j.appender.filter.MaxBackupIndex = 9
log4j.appender.filter.BufferedIO = true
log4j.appender.mqtt = org.apache.log4j.RollingFileAppender
log4j.appender.mqtt.layout = org.apache.log4j.PatternLayout
log4j.appender.mqtt.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}; %m%n
log4j.appender.mqtt.File = /var/log/solarnode/mqtt-solarin.log
log4j.appender.mqtt.MaxFileSize = 10MB
log4j.appender.mqtt.MaxBackupIndex = 9
log4j.appender.mqtt.BufferedIO = true
log4j.appender.flux = org.apache.log4j.RollingFileAppender
log4j.appender.flux.layout = org.apache.log4j.PatternLayout
log4j.appender.flux.layout.ConversionPattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}; %m%n
log4j.appender.flux.File = /var/log/solarnode/mqtt-solarflux.log
log4j.appender.flux.MaxFileSize = 10MB
log4j.appender.flux.MaxBackupIndex = 9
log4j.appender.flux.BufferedIO = true
The various log4j.logger.net.solarnetwork.node.X = INFO, Y lines both set the logging level and
the appender name to write the message to. So = INFO, filter means write INFO level log messages
to the filter appender.
The various log4j.additivity.net.solarnetwork.node.X = false lines disable appender additivity
which means the log message will only be written to one appender, instead of the default of being
written to all configured appenders.
The BufferedIO = true 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.
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