Taming openHAB 2 Logging

While we are at it, I’ve posted aa solution on how to send the logs to a Logstash/Elasticsearch server here:

2 Likes

@Dim, thanks for very specific information about maxFileSize and maxBackupIndex. Where are these variables set? Also, maxFileSize is clear. Is maxBackupIndex the maximum number of backup files kept? Once the maxBackupIndex number is reached, the oldest file is deleted? Just collecting information for a contribution to the documentation.

@otherCommenters, all good information, and probably need a single article collecting all the information here and other places about logging overall. That said, I think it is important to add a section about default logging rollover policy in the installation documentation so sysadmins such as myself don’t freak out worrying about systems falling over in the middle of the night because of full disks. I am still on vacation, but I hope to put together a short contribution when I get back.

  1. /var/lib/openhab2/etc/org.ops4j.pax.logging.cfg
  2. Yes
  3. Yes
  4. Bravo ! :slight_smile: (keep in mind that soon, openHAB2 will be upgraded to use Karaf 4.1.x with log4j2)

https://logging.apache.org/log4j/2.x/manual/migration.html

New log4j2 example here: Log4j2 Sample Config

20-200% performance improvement with the new RollingRandomAccessFileAppender !

Source: https://logging.apache.org/log4j/2.0/performance.html#whichAppender

2 Likes

Speaking of Karaf 4.1.x and the new log4j2: with my old 2.2 snapshot that was around #995ish i could filter log output on the console like this

log:tail | grep -v somestring

After upgrading to #1010 the grep -v part of the commandline is ignored. Is this a known new feature?

I am currently setting up my logging preferences and would like to log detailed (DEBUG level) infos to a file while only displaying INFO level stuff in the console. Is that possible somehow?

I tried something like this:

log4j.logger.org.openhab.binding.mysensors = INFO, osgi:*
log4j.logger.org.openhab.binding.mysensors = DEBUG, mysensors:*

where the mysensors binding is what I want to log and ‘mysensors’ is a file logger I created. I am getting an error message though.

Also what does the :* do? I copied that one from the demo rules.

Hi All,

looking into “my” configuration of the logging, all entries start with log4j2 instead of log4j?

To make use of these suggestions above, can I just change this, or what’s the story.
Sorry - but I am confused.

BTW: I am using the 2.2 Snapshot

Michael

As @Dim mentioned above, the latest snapshot now uses the new log4j2. The configuration files are different and you should read the official documentation linked above.

See also:

Since my problem is related to logging i append it here.
Isn’t it possible to handle the log files with logrotate anymore? I have the following set up:

/etc/logrotate.d/openhab
	
		/var/log/openhab2/openhab.log {
		rotate 6
		daily
		nocompress
		missingok
		copytruncate
		}

problem is the copytruncate. When a logrotate is done the new logfile is as big as the old one (and messed up) and new logs are appended. In notepad++ it looks like this:

How can i solve this? Thanks :slight_smile:

P.S.:I am on the latest snapshot.

You do realize that openHAB rotates its own log files right? I’m not sure what would happen if you tried to rotate the log out from under it but I would not expect it to work, as you are seeing. Is there something wrong with letting OH do it for you?

Thats right, but i prefer having a logfile for each day instead of a 10mb file. I didn’t find a way to implement that in the OH2 logging system.

It worked before but it seems to have stopped a few days/weeks ago.

Are you on an SD card? If so I’m willing to bet real money your SD card is failing. I discovered I had a failing SD card when logrotate stopped working and my syslog filled up the whole file system.

1 Like

Yes i am on a SDcard. Do you have some advise on how to find out if it is really failing? Maybe a an app that tests the card?

No advice needed. If log rotate worked for awhile and doesn’t anymore your SD card is failing. End of story. Backup what you can NOW. Verify the files are not corrupted (most likely they are not), and switch out to a new SD card.

5 Likes

Hi!

Just upgraded to 2.2.0 #1066 and I cannot get separate logging to work with log4j2, I’ve tried to configure separate log files for netatmo and rules by adding the following lines:

### Custom Loggers ###
# Logger - netatmo.log
log4j2.logger.netatmo.name = openhab.binding.netatmo
log4j2.logger.netatmo.level = DEBUG
log4j2.logger.netatmo.additivity = false
log4j2.logger.netatmo.appenderRefs = netatmo
log4j2.logger.netatmo.appenderRef.netatmo.ref = NETATMO

log4j2.logger.rules.name = smarthome.model.script.RULES
log4j2.logger.rules.level = DEBUG
log4j2.logger.rules.additivity = false
log4j2.logger.rules.appenderRefs = rules
log4j2.logger.rules.appenderRef.rules.ref = RULES

# Audit file appender
log4j2.appender.netatmo.type = RollingRandomAccessFile
log4j2.appender.netatmo.name = NETATMO
log4j2.appender.netatmo.fileName = /var/log/openhab2/netatmo.log
log4j2.appender.netatmo.filePattern = /var/log/openhab2/netatmo.log.%i
log4j2.appender.netatmo.append = true
log4j2.appender.netatmo.layout.type = PatternLayout
log4j2.appender.netatmo.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.netatmo.policies.type = Policies
log4j2.appender.netatmo.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.netatmo.policies.size.size = 10MB
log4j2.appender.netatmo.strategy.type = DefaultRolloverStrategy
log4j2.appender.netatmo.strategy.max = 10

log4j2.appender.rules.type = RollingRandomAccessFile
log4j2.appender.rules.name = RULES
log4j2.appender.rules.fileName = /var/log/openhab2/rules.log
log4j2.appender.rules.filePattern = /var/log/openhab2/rules.log.%i
log4j2.appender.rules.append = true
log4j2.appender.rules.layout.type = PatternLayout
log4j2.appender.rules.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.rules.policies.type = Policies
log4j2.appender.rules.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.rules.policies.size.size = 10MB
log4j2.appender.rules.strategy.type = DefaultRolloverStrategy
log4j2.appender.rules.strategy.max = 10

The logfiles are created but remains empty:

-rw-r--r-- 1 openhab openhab        0 Oct 21 23:07 netatmo.log
-rw-r--r-- 1 openhab openhab        0 Oct 21 23:07 rules.log
-rw-r--r-- 1 openhab openhab      214 Oct 22 00:37 audit.log
-rw-r--r-- 1 openhab openhab   330214 Oct 22 01:00 openhab.log
-rw-r--r-- 1 openhab openhab   359114 Oct 22 01:01 events.log

Any clues?

BR,

/Janne

I haven’t upgraded to a log4j2 yet so won’t be able to help.

See @Dim’s “Custom Config”: Log4j2 Sample Config

1 Like

Hi!

Thanks for the tip, @Dim’s “Custom Config” was my inspiration, but I must have missed some detail.

BR,

/Janne

Mine too :grinning:

Here is my example: zwave custom logging and rules logging into an “extra.log” (for example logInfo("EXTRA", "PRESENCE: Somebody is home") )

### Custom Loggers ###
# ZWave
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


# EXTRA
log4j2.logger.rules.name = org.eclipse.smarthome.model.script.EXTRA
log4j2.logger.rules.level = INFO
log4j2.logger.rules.additivity = false
log4j2.logger.rules.appenderRefs = Extra
log4j2.logger.rules.appenderRef.Extra.ref = EXTRA


### Custom Appenders ###
# ZWave
log4j2.appender.ZWave.name = ZWAVE
log4j2.appender.ZWave.type = RollingRandomAccessFile
log4j2.appender.ZWave.fileName = /opt/openhab2/userdata/logs/zwave.log
log4j2.appender.ZWave.filePattern = /opt/openhab2/userdata/logs/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{dd-MMM-yyyy HH:mm:ss.SSS} [%-5.5p] [%-50.50c] - %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

# EXTRA
log4j2.appender.Extra.name = EXTRA
log4j2.appender.Extra.type = RollingRandomAccessFile
log4j2.appender.Extra.fileName = /opt/openhab2/userdata/logs/extra.log
log4j2.appender.Extra.filePattern = /opt/openhab2/userdata/logs/extra.log.%i
log4j2.appender.Extra.immediateFlush = true
log4j2.appender.Extra.append = true
log4j2.appender.Extra.layout.type = PatternLayout
log4j2.appender.Extra.layout.pattern = %d{dd-MMM-yyyy HH:mm:ss.SSS} [%-5.5p] [%-50.50c] - %m%n
log4j2.appender.Extra.policies.type = Policies
log4j2.appender.Extra.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.Extra.policies.size.size = 10MB
log4j2.appender.Extra.strategy.type = DefaultRolloverStrategy
log4j2.appender.Extra.strategy.max = 10

Edit: note that I am using a manual install, not an apt-get, regarding the folder structure

Hi!

Thank’s for your example,now it works! :slight_smile: I’ve missed the full package path in the line (The leading org. was missing):

log4j2.logger.rules.name = org.eclipse.smarthome.model.script.RULES

BR,

/Janne

2 Likes