Can't get a separate log file for the verisure binding

  • Platform information:

    • Hardware: x86_64/4GB/120GB
    • OS: Ubuntu 18.04.5 LTS / kernel 4.15.0-117-generic
    • Java Runtime Environment: openjdk version “1.8.0_262”
    • openHAB version: 2.5.7-1
  • Issue of the topic:
    I can’t manage to get the output of the verisure binding to a separate logfile as described by the OH documentation. It works for other bindings. This is the entries in org.ops4j.pax.logging.cfg:

    # Verisure Logger
    log4j2.logger.verisure.name = org.openhab.binding.verisure
    log4j2.logger.verisure.level = DEBUG
    log4j2.logger.verisure.additivity = false
    log4j2.logger.verisure.appenderRefs = verisure
    log4j2.logger.verisure.appenderRef.verisure.ref = VERISURE
    
    # Verisure File Appender - verisure.log
    log4j2.appender.verisure.name = VERISURE
    log4j2.appender.verisure.type = RollingRandomAccessFile
    log4j2.appender.verisure.fileName = ${openhab.logdir}/verisure.log
    log4j2.appender.verisure.filePattern = ${openhab.logdir}/verisure.log.%i
    log4j2.appender.verisure.immediateFlush = true
    log4j2.appender.verisure.append = true
    log4j2.appender.verisure.layout.type = PatternLayout
    log4j2.appender.verisure.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
    log4j2.appender.verisure.policies.type = Policies
    log4j2.appender.verisure.policies.size.type = SizeBasedTriggeringPolicy
    log4j2.appender.verisure.policies.size.size = 3MB
    log4j2.appender.verisure.strategy.type = DefaultRolloverStrategy
    log4j2.appender.verisure.strategy.max = 10
    
    log4j2.logger.org_openhab_binding_verisure.level = DEBUG
    log4j2.logger.org_openhab_binding_verisure.name = org.openhab.binding.verisure
    

    The last two entries are what is created by default from openhab when running log:set DEBUG org.openhab.binding.verisure. That works, the debug output is coming to the openhab.log, but not to verisure.log.

    This is the output of log:get ALL:

    Logger                                             │ Level
    ___________________________________________________|______
    ROOT                                               │ WARN
    javax.jmdns                                        │ ERROR
    javax.mail                                         │ ERROR
    org.apache.karaf.jaas.modules.audit                │ INFO
    org.apache.karaf.kar.internal.KarServiceImpl       │ ERROR
    org.apache.karaf.shell.ssh.SshUtils                │ ERROR
    org.apache.karaf.shell.support                     │ OFF
    org.apache.sshd                                    │ ERROR
    org.eclipse.lsp4j                                  │ OFF
    org.eclipse.smarthome                              │ INFO
    org.eclipse.smarthome.model.script.timerlights     │ DEBUG
    org.jupnp                                          │ ERROR
    org.openhab                                        │ INFO
    org.openhab.binding.nibeuplink                     │ INFO
    org.openhab.binding.rfxcom                         │ DEBUG
    org.openhab.binding.smhi                           │ DEBUG
    org.openhab.binding.verisure                       │ INFO
    org.openhab.binding.zwave                          │ DEBUG
    org.openhab.ui.paper                               │ WARN
    org.openhab.ui.paper.internal                      │ INFO
    org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
    org.ops4j.pax.web.pax-web-runtime                  │ OFF
    smarthome.event                                    │ INFO
    smarthome.event.InboxUpdatedEvent                  │ ERROR
    smarthome.event.ItemAddedEvent                     │ ERROR
    smarthome.event.ItemRemovedEvent                   │ ERROR
    smarthome.event.ItemStateEvent                     │ ERROR
    smarthome.event.ThingAddedEvent                    │ ERROR
    smarthome.event.ThingRemovedEvent                  │ ERROR
    smarthome.event.ThingStatusInfoEvent               │ ERROR
    

    Another observation I made is that when using log:set to change the loglevel to INFO on for example the zwave binding, the output from log:get still shows DEBUG as it should because I have made the same configuration for the zwave binding, with DEBUG loglevel to a separate log file. However when changing the loglevel to INFO on the verisure binding, it also changes in the output from log:get. It is as if openhab ignores my configuration for the verisure binding?

    I don’t know if this is a problem with the logging facility, with the binding or with my configuration. Any help nailing down the problem would be much appreciated!

The only difference I see between this and the zwave config I have is that appenderRefs, appenderRef.verisure.ref, and the appender name are all identical. You have appenderRefs all lower case.

I don’t look at logs through the console so I can’t comment on the other behaviors you see.

Do you have any suggestions on how to troubleshoot this? Any form of debug logging that can be activated or other other ways to peek inside and see why the configuration does not work?

Read through the Log4j2 docs and see if some error becomes apparent. All I can offer is it can work so there must be something wrong that is not apparent with your config.

1 Like

@brydling

I would try the following:

delete this two lines from your org.ops4j.pax.logging.cfg (shown above):

log4j2.logger.org_openhab_binding_verisure.level = DEBUG
log4j2.logger.org_openhab_binding_verisure.name = org.openhab.binding.verisure

.

Then restart openhab.
.

P.S: I tested it on my “OH2 test machine”, and it creates a separate logfile.

1 Like

I had a similar question and applied your hints and it works for me :grinning:

2 Likes

I’ve missed all these replies. Sorry guys. But thanks for the suggestions! Somehow I solved the problem, but don’t remember how right now :slight_smile:

This is the current config in case anyone’s interested:

# Verisure Logger
log4j2.logger.VERISURE.name = org.openhab.binding.verisure
log4j2.logger.VERISURE.level = DEBUG
log4j2.logger.VERISURE.additivity = false
log4j2.logger.VERISURE.appenderRefs = VERISURE
log4j2.logger.VERISURE.appenderRef.VERISURE.ref = VERISURE

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

log4j2.logger.org_openhab_binding_verisure.level = DEBUG
log4j2.logger.org_openhab_binding_verisure.name = org.openhab.binding.verisure

Looks like I just made it uppercase… But that is not how I have it for other bindings so don’t know why it didn’t work for this one.