Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Update logging instruction for OH3 #1303

Merged
merged 4 commits into from
Dec 13, 2020
Merged

Update logging instruction for OH3 #1303

Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
4dd3de0
Update logging instruction for OH3
mstormi Dec 10, 2020
7a6d7ca
Update administration/logging.md
mstormi Dec 13, 2020
bcb8f7d
Removed logback info as that is only used in development
mstormi Dec 13, 2020
5196abc
Merge branch 'main' into patch-16
mstormi Dec 13, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
200 changes: 25 additions & 175 deletions administration/logging.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,24 +7,24 @@ title: Logging

# Logging in openHAB

This article describes the logging functionality in openHAB 2.
This article describes the logging functionality in openHAB.
This includes how to access logging information and configure logging for user-defined rules.

There are two ways to check log entries:

1. Through files stored on the **file system**
2. During runtime in the **Karaf Console**

## File System
## Filesystem

Log files are written to either `userdata/log` (manual setup) or `/var/log/openhab2` (apt/deb-based setup) and can be accessed using standard OS tools for text files. The default installation of openHAB generates two log files:
Log files are written to either `userdata/log` (manual setup) or `/var/log/openhab` (package based setup) and can be accessed using standard OS tools for text files. The default installation of openHAB generates two log files:

- `events.log`
- `openhab.log`

## Karaf Console
## Console

The [Karaf console](console.html) allows to monitor the log in real-time.
The [openHAB console](console.html) allows to monitor the log in real-time.

The log shell comes with the following commands:

Expand Down Expand Up @@ -59,9 +59,13 @@ openhab> log:tail org.openhab.io.rest.core.item.ItemResource

Please see the [Karaf documentation](http://karaf.apache.org/manual/latest/#_commands_2) for more examples and details.

## Config File
## Config file

The config file for logging is `org.ops4j.pax.logging.cfg` located in the `userdata/etc` folder (manual setup) or in `/var/lib/openhab2/etc` (apt/deb-based setup).
The config file for logging is located in the `userdata/etc` folder (manual setup) or in `/var/lib/openhab/etc` (apt/deb-based setup).

::: tip Attention OH2 users
The format and filename to store log settings has changed. It used to be `org.ops4j.pax.logging.cfg` in openHAB 2 and became `log4j2.xml`in openHAB 3.
:::

## Defining what to log

Expand Down Expand Up @@ -127,200 +131,46 @@ log:set DEBUG org.openhab.binding.zwave
Note that the log levels set using the `log:set` commands are persistent and will be applied upon restart.
To modify the stored log levels, use the console or edit the [configuration file](#config-file).

## Create Log Entries in Rules
## Create log entries in rules

There are times, especially when troubleshooting rules, when it can be helpful to write information and variable or Item State values to the log.
There are times, especially when troubleshooting rules, when it can be helpful to log information or Item state values.

For each log level there is an corresponding command for creating log entries.
You may use these log levels to filter or better differentiate the generated logging output.
The logging commands require two parameters: the subpackage, in the examples below `heating-control.rules`, and the text which should appear in the log:
The logging commands require two parameters: the subpackage, in the examples below `heating`, and the text which should appear in the log:

```java
logError("heating-control.rules", "This is a log entry of type Error!")
logWarn("heating-control.rules", "This is a log entry of type Warn!")
logInfo("heating-control.rules", "This is a log entry of type Info!")
logDebug("heating-control.rules", "This is a log entry of type Debug!")
logError("heating", "This is a log entry of type Error!")
logWarn("heating", "Heating control failed while in mode {}", Heating_Mode.state)
logInfo("heating", "Heating mode set to normal")
logDebug("heating", "Bedroom: Temperature: {}, Mode: {}", Bedroom_Temp.state, Bedroom_Heater_Mode.state)logWarn("heating", "This is a log entry of type Warn!")
```

The main package of all script/rules based log entries is predefined as `org.openhab.model.script`.
The main package of all script/rules based log entries is predefined as `org.openhab.core.model.script`.
The chosen subpackage is appended to the end of the main package.
It can be useful for filtering or package-based log level settings.

Examples for typical logging lines found in rules:

```text
logInfo("heating-control.rules", "Heating mode set to normal")
logWarn("heating-control.rules", "Heating control failed while in mode {}", Heating_Mode.state)
logDebug("heating-control.rules", "Bedroom: Temperature: {}, Mode: {}", Bedroom_Temp.state, Bedroom_Heater_Mode.state)
```
For example you can use `log:set info org.openhab.core.model.script` and `log:set info org.openhab.core.model.script.heating` while you work on the heating rules to get debug level output for heating rules and only info level for the rest of your rules files so you don't flood the log with too many entries that are irrelevant at that point in time.

An example output of the last log statement above is:

```
2016-06-04 16:28:39.482 [DEBUG] [.e.model.script.heating-control.rules] Bedroom: Temperature 21.3°C, Mode NORMAL
2016-06-04 16:28:39.482 [DEBUG] [org.openhab.core.model.script.heating] Bedroom: Temperature 21.3°C, Mode NORMAL
```

Note that, in the last example above, inclusion and formatting of values is done using [Java Formatter String Syntax](https://docs.oracle.com/javase/7/docs/api/java/util/Formatter.html).

## Logging into Separate File
## Log4j configuration and logging into separate files

Per default all log entries are saved in the file `openhab.log` and event specific entries are saved in `events.log`.
As per default, all log entries are saved in the file `openhab.log` and event specific entries are saved in `events.log`.
Additional files can be defined in order to write specifics logs to a separate place.

In order to create a new log file following two areas needs to be added to the [configuration file](#config-file):

**New logger:**

```java
# ZWave Logger
log4j2.logger.ZWave.name = org.openhab.binding.zwave
log4j2.logger.ZWave.level = INFO
log4j2.logger.ZWave.additivity = false
log4j2.logger.ZWave.appenderRefs = ZWave
log4j2.logger.ZWave.appenderRef.ZWave.ref = ZWAVE
```

**New file appender:**

```java
# ZWave File Appender - ZWave.log
log4j2.appender.ZWave.name = ZWAVE
log4j2.appender.ZWave.type = RollingRandomAccessFile
log4j2.appender.ZWave.fileName = ${openhab.logdir}/ZWave.log
log4j2.appender.ZWave.filePattern = ${openhab.logdir}/ZWave.log.%i
log4j2.appender.ZWave.immediateFlush = true
log4j2.appender.ZWave.append = true
log4j2.appender.ZWave.layout.type = PatternLayout
log4j2.appender.ZWave.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.ZWave.policies.type = Policies
log4j2.appender.ZWave.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.ZWave.policies.size.size = 10MB
log4j2.appender.ZWave.strategy.type = DefaultRolloverStrategy
log4j2.appender.ZWave.strategy.max = 10
```

## Logback Configuration File

In order to define custom log patterns, log to network sockets and so on we can prepare a logging configuration file.

There are several things, that you might want to change in the configuration:
In order to define custom log patterns, log to network sockets and so on we can prepare a logging configuration in `log4j2.xml`.
There are several things that you might want to change in the configuration:

- the log level for a logger;
- the pattern of an appender;
- redirect the log to a text file.

The configuration file for openHAB is placed in the [openhab-distro/lauch/home/logback_debug.xml](https://github.com/openhab/openhab-distro/blob/master/launch/home/logback_debug.xml) file. We have added a few comments on this file in order to attract your attention on some significant points:

```xml
<configuration scan="true">

<!-- This is the appender that displays the logging on the console -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<!-- This pattern will display the time, the log level, the name of the logger and the log message -->
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5level] [%-30.30logger{36}:%-5line] - %msg%ex{10}%n</pattern>
</encoder>
</appender>

<!-- Another appender that logs into a file -->
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>${openhab.logdir:-userdata/logs}/openhab.log</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5level] [%-30.30logger{36}:%-5line] - %msg%ex{10}%n</pattern>
</encoder>
</appender>

<!-- We have removed part of the original file in this example -->
...


<logger name="smarthome.event" level="INFO" additivity="false">
<!-- The element <logger> may contain zero or more <appender-ref> elements -->
<appender-ref ref="EVENTFILE" />
<appender-ref ref="STDOUT" />
</logger>

<!-- Logback uses inheritance to determine the log level.
If a given logger is NOT assigned a level it inherits one from the its closest ancestor -->
<logger name="org.openhab" level="DEBUG" />
<logger name="org.openhab" level="DEBUG" />

<logger name="org.eclipse.jetty" level="INFO" />
<logger name="org.jupnp" level="ERROR"/>
<logger name="javax.jmdns" level="OFF"/>
<logger name="javax.jmdns.impl" level="OFF"/>
<logger name="javax.jmdns.impl.constants" level="OFF"/>
<logger name="tuwien.auto.calimero" level="WARN" />

<!-- The root logger is at the top of the logger hierarchy.
All loggers inherit its level, if there are no ancestors
between the root and the logger -->
<root level="INFO">
<appender-ref ref="FILE" />
<appender-ref ref="STDOUT" />
</root>

<logger name="OSGi" level="OFF" />

</configuration>

```

If you are not aware of [appenders](http://logback.qos.ch/manual/appenders.html) and [logger elements](http://logback.qos.ch/manual/configuration.html#loggerElement), you might want to take a look at the links to the the logback documentation.

You can pass the start argument `-Dlogback.configurationFile` to use your own logging configuration file.

### Setting up the Log Level

As you can see from the example configuration file above, the level for jUPnP is set to ERROR. If you develop a binding that is using jUPnP, you might want to see more logs on your console. You can simply change the log level to TRACE or DEBUG:

```xml
<logger name="org.jupnp" level="TRACE"/>
```

### Changing the Pattern of an Appender

Another useful option is to change the pattern of an appender.
This pattern defines what information will be logged.
The logback logger provides many [predefined conversion words](http://logback.qos.ch/manual/layouts.html#conversionWord) for the most common use cases.
Use the most appropriate ones for your specific case.
For the purpose of exploring and debugging multithreaded applications you might need to see which thread has generated certain log event.
In order to see this in the logs, you have to add the conversion word `t` to the pattern above:

```xml
<pattern>%t %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5level] [%-30.30logger{36}:%-5line] - %msg%ex{10}%n</pattern>
```

### Redirect the Log to a Text File

You might want to redirect your log to a text file.
This gives you the flexibility to search easier for a specific log or to save your logs.
If you have looked at the [default configuration file](#logback-configuration-file) you might have noticed that several appenders are listed there.
The process of redirecting the log to a text file is as simple as :

- adding a new `FileAppender` and specifying the path of the output file:

```xml
<appender name="YOUR_APPENDER_NAME" class="ch.qos.logback.core.FileAppender">
<file>relative/path/to/file.log</file>
<encoder>
<!--Pick up a pattern that will log the information that you will need -->
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5level] [%-30.30logger{36}:%-5line] - %msg%ex{10}%n</pattern>
</encoder>
</appender>
```
- adding your logger, setting up the log level and adding `appender-ref` element to the logger element.
For this example we will assume that you want to add the following logger with the name `com.logger.example`:

```xml
<logger name="com.logger.example" level="INFO">
<appender-ref ref="YOUR_APPENDER_NAME" />
</logger>
```

### Further Reading

- <http://www.slf4j.org/>
- <http://logback.qos.ch/>
- <http://www.slf4j.org/manual.html>
- <http://stackoverflow.com/questions/6699537/how-to-use-multiple-configurations-with-logback-in-a-single-project>