Taming openHAB 2 Logging

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

I am trying to get my Zwave logging working again after updating to 2.2.0. Tried implementing the suggestions in this thread and sample config from @Dim. The appender creates the ZWave.log file, but it stays empty. Can anyone point me in the right direction as to what the problem may be?

# Common pattern layout for appenders
#log4j2.pattern = %d{ISO8601} | %-5p | %-16t | %-32c{1} | %X{bundle.id} - %X{bundle.name} - %X{bundle.version} | %m%n

# Root logger
log4j2.rootLogger.level = WARN
log4j2.rootLogger.appenderRefs = out, osgi
log4j2.rootLogger.appenderRef.out.ref = LOGFILE
log4j2.rootLogger.appenderRef.osgi.ref = OSGI

# Karaf Shell logger
log4j2.logger.shell.name = org.apache.karaf.shell.support
log4j2.logger.shell.level = OFF
log4j2.logger.shell.appenderRefs = stdout
log4j2.logger.shell.appenderRef.stdout.ref = STDOUT

# Security audit logger
log4j2.logger.audit.name = org.apache.karaf.jaas.modules.audit
log4j2.logger.audit.level = INFO
log4j2.logger.audit.additivity = false
log4j2.logger.audit.appenderRefs = audit
log4j2.logger.audit.appenderRef.audit.ref = AUDIT

# openHAB specific logger configuration

log4j2.logger.openhab.name = org.openhab
log4j2.logger.openhab.level = INFO
# log4j2.logger.openhab.level = DEBUG

log4j2.logger.smarthome.name = org.eclipse.smarthome
log4j2.logger.smarthome.level = INFO
# log4j2.logger.smarthome.level = DEBUG

log4j2.logger.smarthomeItemStateEvent.name = smarthome.event.ItemStateEvent
log4j2.logger.smarthomeItemStateEvent.level = ERROR
log4j2.logger.smarthomeItemAddedEvent.name = smarthome.event.ItemAddedEvent
log4j2.logger.smarthomeItemAddedEvent.level = ERROR
log4j2.logger.smarthomeItemRemovedEvent.name = smarthome.event.ItemRemovedEvent
log4j2.logger.smarthomeItemRemovedEvent.level = ERROR
log4j2.logger.smarthomeThingStatusInfoEvent.name = smarthome.event.ThingStatusInfoEvent
log4j2.logger.smarthomeThingStatusInfoEvent.level = ERROR
log4j2.logger.smarthomeThingAddedEvent.name = smarthome.event.ThingAddedEvent
log4j2.logger.smarthomeThingAddedEvent.level = ERROR
log4j2.logger.smarthomeThingRemovedEvent.name = smarthome.event.ThingRemovedEvent
log4j2.logger.smarthomeThingRemovedEvent.level = ERROR
log4j2.logger.smarthomeInboxUpdatedEvent.name = smarthome.event.InboxUpdatedEvent
log4j2.logger.smarthomeInboxUpdatedEvent.level = ERROR

log4j2.logger.events.name = smarthome.event
log4j2.logger.events.level = INFO
log4j2.logger.events.additivity = false
log4j2.logger.events.appenderRefs = event
log4j2.logger.events.appenderRef.event.ref = EVENT
log4j2.logger.events.appenderRef.osgi.ref = OSGI

log4j2.logger.jupnp.name = org.jupnp
log4j2.logger.jupnp.level = ERROR

log4j2.logger.jmdns.name = javax.jmdns
log4j2.logger.jmdns.level = ERROR

#log4j2.logger.org.ops4j.pax.web.service.jetty.internal.JettyServerWrapper = ERROR
#log4j2.logger.org.ops4j.pax.web.service.jetty.internal.JettyServerWrapper = ERROR
#log4j2.logger.org.apache.karaf.kar.internal.KarServiceImpl = ERROR

# Appenders configuration

# Console appender not used by default (see log4j2.rootLogger.appenderRefs)
log4j2.appender.console.type = Console
log4j2.appender.console.name = STDOUT
log4j2.appender.console.layout.type = PatternLayout
log4j2.appender.console.layout.pattern = %d{HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n

# Rolling file appender
log4j2.appender.out.type = RollingRandomAccessFile
log4j2.appender.out.name = LOGFILE
log4j2.appender.out.fileName = /var/log/openhab2/openhab.log
log4j2.appender.out.filePattern = /var/log/openhab2/openhab.log.%i
log4j2.appender.out.immediateFlush = true
log4j2.appender.out.append = true
log4j2.appender.out.layout.type = PatternLayout
log4j2.appender.out.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.out.policies.type = Policies
log4j2.appender.out.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.out.policies.size.size = 16MB

# Event log appender
log4j2.appender.event.type = RollingRandomAccessFile
log4j2.appender.event.name = EVENT
log4j2.appender.event.fileName = /var/log/openhab2/events.log
log4j2.appender.event.filePattern = /var/log/openhab2/events.log.%i
log4j2.appender.event.immediateFlush = true
log4j2.appender.event.append = true
log4j2.appender.event.layout.type = PatternLayout
log4j2.appender.event.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-26.26c] - %m%n
log4j2.appender.event.policies.type = Policies
log4j2.appender.event.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.event.policies.size.size = 16MB

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

# OSGi appender
log4j2.appender.osgi.type = PaxOsgi
log4j2.appender.osgi.name = OSGI
log4j2.appender.osgi.filter = *
log4j2.logger.org_openhab_binding_zwave.level = DEBUG
log4j2.logger.org_openhab_binding_zwave.name = org.openhab.binding.zwave

### Custom Loggers ###
# ZWave
log4j2.logger.ZWave.name = org.openhab.binding.zwave
log4j2.logger.ZWave.level = DEBUG
log4j2.logger.ZWave.additivity = false
log4j2.logger.ZWave.appenderRefs = ZWave
log4j2.logger.ZWave.appenderRef.ZWave.ref = ZWAVE

### Custom Appenders ###
# ZWave
log4j2.appender.ZWave.name = ZWAVE
log4j2.appender.ZWave.type = RollingRandomAccessFile
log4j2.appender.ZWave.fileName = /var/log/openhab2/ZWave.log
log4j2.appender.ZWave.filePattern = /var/log/openhab2/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


Compare it to my working example above:

I did. The only difference I can see (for Zwave) is:
Logger: you have INFO and I have DEBUG
Appender: We have different paths because mine installation is apt based

Or am I completely blind? :confused:

Just a guess on my part but I think the problem may be the # OSGi appender section just above your ### Custom Loggers ### section. I think that section was added if you set your zwave binding to debug in Karaf and may be overriding your custom appender. Once again, this is just a guess.

I added @sihui zwave code to the end of my cfg and everything works fine. I also changed the level to DEBUG and the DEBUG info started showing up in my zwave.log file. I do not have a OSGi appender section in my config though, nor did I ever change to DEBUG in Karaf.

Just a thought. :slightly_smiling_face:

2 Likes

Brilliant guess, Bill :grinning: I was about to just copy Dim’s full config and get done with it. Though I was wondering about that additional zwave logger in the osgi section too. Then I saw your post and commented out that logger. Problem solved, thanks! :beer:

1 Like

Just adding this here since I couldn’t find it again after doing it almost a year ago, and the OH2.2 upgrade reverted the /srv/openhab2-userdata/etc/org.ops4j.pax.logging.cfg file.

Simple string filtering on the event log. Useful for filtering out high change items that don’t need constant log visibility.

Prior to OH2.2 - using log4j

# Jp - filter out stuff
log4j.appender.event.filter.smappee=org.apache.log4j.varia.StringMatchFilter
log4j.appender.event.filter.smappee.StringToMatch=power_smappee
log4j.appender.event.filter.smappee.AcceptOnMatch=false

Taken from an example in Log4j2 Sample Config, the following appears to do the same under OH2.2

# Jp - filter out stuff
log4j2.appender.event.filter.regex.type = RegexFilter
log4j2.appender.event.filter.regex.regex = .*power_smappee.*
log4j2.appender.event.filter.regex.onMatch = DENY
log4j2.appender.event.filter.regex.onMisMatch = ACCEPT

There are probably better ways to do it, but for now that works, and excludes the power_smappee (power consumption, changes by the second) from the log files.

Thx.
Jp.

5 Likes

It would be great if you post this as its own thread in Examples and Tutorials. Lots of people have asked for how to filter out events from events.log.

1 Like

Took your advice and split it out into it’s own post. Since I had such a hard time finding the information originally (and after updating with OH2.2 replacing the config file) I don’t doubt you’re right it’s something a lot of people ask for.

New topic is at : OpenHAB - Filtering event logs

It’s pretty straightforward as configuration goes, and hopefully adding the filtering reference to the topic name should help people find it readily enough.

Thx.
Jp.

2 Likes

Side hint: If you change you logging conf and the change does not seem to work, check if the lines you changed have trailing whitespaces ! It took me several hours to figure that out - so I like to save that time to you … :smiley:

1 Like

log4j also seems to privide a CronTriggeringPolicy in order to rotate the log. For example rotating at midnight.

Did someone already manage to implement that? I tried but failed because all examples found in the internet use xml and not this openhabs approach.

I was asking something similar here:

Unfortunately official documentation is for the xml file which was discontinued with OH2.
I am not sure why and nobody answered me. Maybe beacuse things would be too easy, then! :wink: