Event State logging in events.log dosn't work

Thomas_Kolbe · August 7, 2022, 11:54am

Hi folks,

some weeks ago I finaly took all the effort and changed from OH2.5 to OH3.3.0 with a clean install of openhabian on my Raspi.

Since that movement, the entries of the events.log don’t show any item state changes, so it’s difficult to debug the transfer of my script based rules from OH2 to OH3. I think I read all relevant posts of how to configure the logging levels, but still I got no item state logs in my events.log file. Log level is set to INFO via karaf console and even via change of the log4j2.xml, both show log level INFO (see screenshot).

Can anyone help me, where else I have to do changes to see logs of item state changes?

Thx in advance
Tom
grafik

Udo_Hartmann · August 7, 2022, 1:29pm

Please take a look at /var/lib/openhab/etc/org.ops4j.pax.logging.cfg, it should look like this:

org.ops4j.pax.logging.log4j2.config.file=${karaf.etc}/log4j2.xml

And of course there should be a file named log4j2.xml in the same folder.

Another thing…
My list looks quite different:

openhab> log:list
Logger                                             │ Level
───────────────────────────────────────────────────┼──────
ROOT                                               │ WARN
javax.jmdns                                        │ ERROR
javax.mail                                         │ ERROR
openhab.event                                      │ INFO
openhab.event.AddonEvent                           │ ERROR
openhab.event.ChannelDescriptionChangedEvent       │ ERROR
openhab.event.InboxUpdatedEvent                    │ ERROR
openhab.event.ItemAddedEvent                       │ ERROR
openhab.event.ItemChannelLinkAddedEvent            │ ERROR
openhab.event.ItemChannelLinkRemovedEvent          │ ERROR
openhab.event.ItemRemovedEvent                     │ ERROR
openhab.event.ItemStateEvent                       │ ERROR
openhab.event.RuleAddedEvent                       │ ERROR
openhab.event.RuleRemovedEvent                     │ ERROR
openhab.event.RuleStatusInfoEvent                  │ ERROR
openhab.event.StartlevelEvent                      │ ERROR
openhab.event.ThingAddedEvent                      │ ERROR
openhab.event.ThingRemovedEvent                    │ ERROR
openhab.event.ThingStatusInfoEvent                 │ ERROR
openhab.event.ThingUpdatedEvent                    │ ERROR
org.apache.cxf.jaxrs.sse.SseEventSinkImpl          │ ERROR
org.apache.cxf.phase.PhaseInterceptorChain         │ 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.jupnp                                          │ ERROR
org.openhab                                        │ INFO
org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
org.ops4j.pax.web.pax-web-runtime                  │ OFF
su.litvak.chromecast.api.v2.Channel                │ ERROR

and I did noch change anything to logging since fresh install, so maybe log4j2.xml is not correct at all.

<?xml version="1.0" encoding="UTF-8" standalone="no"?><Configuration monitorInterval="10">

        <Appenders>
                <!-- Console appender not used by default (see Root logger AppenderRefs) -->
                <Console name="STDOUT">
                        <PatternLayout pattern="%d{HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
                </Console>

                <!-- Rolling file appender -->
                <RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i.gz" name="LOGFILE">
                        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
                        <Policies>
                                <OnStartupTriggeringPolicy/>
                                <SizeBasedTriggeringPolicy size="16 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="7"/>
                </RollingFile>

                <!-- Event log appender -->
                <RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i.gz" name="EVENT">
                        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
                        <Policies>
                                <OnStartupTriggeringPolicy/>
                                <SizeBasedTriggeringPolicy size="16 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="7"/>
                </RollingRandomAccessFile>

                <!-- Audit file appender -->
                <RollingRandomAccessFile fileName="${sys:openhab.logdir}/audit.log" filePattern="${sys:openhab.logdir}/audit.log.%i.gz" name="AUDIT">
                        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
                        <Policies>
                                <OnStartupTriggeringPolicy/>
                                <SizeBasedTriggeringPolicy size="8 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="7"/>
                </RollingRandomAccessFile>

                <!-- OSGi appender -->
                <PaxOsgi filter="*" name="OSGI"/>
        </Appenders>

        <Loggers>
                <!-- Root logger configuration -->
                <Root level="WARN">
                        <AppenderRef ref="LOGFILE"/>
                        <AppenderRef ref="OSGI"/>
                </Root>

                <!-- Karaf Shell logger -->
                <Logger level="OFF" name="org.apache.karaf.shell.support">
                        <AppenderRef ref="STDOUT"/>
                </Logger>

                <!-- Security audit logger -->
                <Logger additivity="false" level="INFO" name="org.apache.karaf.jaas.modules.audit">
                        <AppenderRef ref="AUDIT"/>
                </Logger>

                <!-- openHAB specific logger configuration -->

                <Logger level="INFO" name="org.openhab"/>

                <Logger level="ERROR" name="openhab.event.ItemStateEvent"/>
                <Logger level="ERROR" name="openhab.event.ItemAddedEvent"/>
                <Logger level="ERROR" name="openhab.event.ItemRemovedEvent"/>
                <Logger level="ERROR" name="openhab.event.ItemChannelLinkAddedEvent"/>
                <Logger level="ERROR" name="openhab.event.ItemChannelLinkRemovedEvent"/>
                <Logger level="ERROR" name="openhab.event.ChannelDescriptionChangedEvent"/>
                <Logger level="ERROR" name="openhab.event.ThingStatusInfoEvent"/>
                <Logger level="ERROR" name="openhab.event.ThingAddedEvent"/>
                <Logger level="ERROR" name="openhab.event.ThingUpdatedEvent"/>
                <Logger level="ERROR" name="openhab.event.ThingRemovedEvent"/>
                <Logger level="ERROR" name="openhab.event.InboxUpdatedEvent"/>
                <Logger level="ERROR" name="openhab.event.RuleStatusInfoEvent"/>
                <Logger level="ERROR" name="openhab.event.RuleAddedEvent"/>
                <Logger level="ERROR" name="openhab.event.RuleRemovedEvent"/>
                <Logger level="ERROR" name="openhab.event.StartlevelEvent"/>
                <Logger level="ERROR" name="openhab.event.AddonEvent"/>

                <Logger additivity="false" level="INFO" name="openhab.event">
                        <AppenderRef ref="EVENT"/>
                        <AppenderRef ref="OSGI"/>
                </Logger>

                <Logger level="ERROR" name="javax.jmdns"/>
                <Logger level="ERROR" name="org.jupnp"/>

                <!-- This suppresses all Maven download issues from the log when doing feature installations -->
                <!-- as we are logging errors ourselves in a nicer way anyhow. -->
                <Logger level="ERROR" name="org.ops4j.pax.url.mvn.internal.AetherBasedResolver"/>

                <!-- Filters known issues of pax-web (issue link to be added here). -->
                <!-- Can be removed once the issues are resolved in an upcoming version. -->
                <Logger level="OFF" name="org.ops4j.pax.web.pax-web-runtime"/>

                <!-- Filters known issues of lsp4j, see -->
                <!-- https://github.com/eclipse/smarthome/issues/4639 -->
                <!-- https://github.com/eclipse/smarthome/issues/4629 -->
                <!-- https://github.com/eclipse/smarthome/issues/4643 -->
                <!-- Can be removed once the issues are resolved in an upcoming version. -->
                <Logger level="OFF" name="org.eclipse.lsp4j"/>

                <!-- Filters warnings for events that could not be delivered to a disconnected client. -->
                <Logger level="ERROR" name="org.apache.cxf.jaxrs.sse.SseEventSinkImpl"/>

                <!-- Filters warnings from broken connections during startup -->
                <!-- https://github.com/openhab/openhab-core/issues/2998 -->
                <Logger level="ERROR" name="org.apache.cxf.phase.PhaseInterceptorChain"/>

                <!-- Filters known issues of KarServiceImpl, see -->
                <!-- https://github.com/openhab/openhab-distro/issues/519#issuecomment-351944506 -->
                <!-- Can be removed once the issues are resolved in an upcoming version. -->
                <Logger level="ERROR" name="org.apache.karaf.kar.internal.KarServiceImpl"/>

                <!-- Filters warnings about unavailable ciphers when JCE is not installed, see -->
                <!-- https://github.com/openhab/openhab-distro/issues/999 -->
                <Logger level="ERROR" name="org.apache.karaf.shell.ssh.SshUtils"/>

                <!-- Filters known issues of javax.mail, see -->
                <!-- https://github.com/openhab/openhab-addons/issues/5530 -->
                <Logger level="ERROR" name="javax.mail"/>

                <!-- Filters disconnection warnings of the ChromeCast Java API, see -->
                <!-- https://github.com/openhab/openhab-addons/issues/3770 -->
                <Logger level="ERROR" name="su.litvak.chromecast.api.v2.Channel"/>

                <!-- Added by Karaf to prevent debug logging loops, see -->
                <!-- https://issues.apache.org/jira/browse/KARAF-5559 -->
                <Logger level="ERROR" name="org.apache.sshd"/>
        </Loggers>

</Configuration>

Thomas_Kolbe · August 7, 2022, 3:31pm

Hi Udo,

thanks for your answer!

My org.ops4j.pax.logging.cfg looks like this (see below), so it seems it contains the log config itself instead of the link to the log4j2.xml file as in your case. But I have as well the log4j2.xml in this folder and it looks exactly like yours, except the Loglevel INFO for all logger.smarthome subpackages like log4j2.logger.smarthomeItemStateEvent.level, what I changed myself because I expected it to do what I want.

If I change log level by using log:set in karaf, the change also apears in the org.ops4j.pax.logging.cfg as well as the log4j2.xml file, so the transfer of the configuration seems to work.

Do you see changes of your items states, like lights on/off or temperature changes, in your events.log with your configuration?

Ciao
Tom

# 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 = ERROR
log4j2.logger.smarthome.level = INFO


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

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.paperui.name = org.openhab.ui.paper
log4j2.logger.paperui.level = WARN
log4j2.logger.paperuiint.name = org.openhab.ui.paper.internal
log4j2.logger.paperuiint.level = INFO

# This suppresses all Maven download issues from the log when doing feature installations
# as we are logging errors ourselves in a nicer way anyhow.
log4j2.logger.paxurl.name = org.ops4j.pax.url.mvn.internal.AetherBasedResolver
log4j2.logger.paxurl.level = ERROR

# Filters known issues of pax-web (issue link to be added here).
# Can be removed once the issues are resolved in an upcoming version.
log4j2.logger.paxweb.name = org.ops4j.pax.web.pax-web-runtime
log4j2.logger.paxweb.level = OFF

# Filters known issues of lsp4j, see
# https://github.com/eclipse/smarthome/issues/4639
# https://github.com/eclipse/smarthome/issues/4629
# Can be removed once the issues are resolved in an upcoming version.
log4j2.logger.lsp4j.name = org.eclipse.lsp4j
log4j2.logger.lsp4j.level = OFF

# Filters known issues of KarServiceImpl, see
# https://github.com/openhab/openhab-distro/issues/519#issuecomment-351944506
# Can be removed once the issues are resolved in an upcoming version.
log4j2.logger.karservice.name = org.apache.karaf.kar.internal.KarServiceImpl
log4j2.logger.karservice.level = ERROR

# Filters warnings about unavailable ciphers when JCE is not installed, see
# https://github.com/openhab/openhab-distro/issues/999
log4j2.logger.sshutils.name = org.apache.karaf.shell.ssh.SshUtils
log4j2.logger.sshutils.level = ERROR

# Filters known issues of javax.mail, see
# https://github.com/openhab/openhab2-addons/issues/5530
log4j2.logger.javaxmail.name = javax.mail
log4j2.logger.javaxmail.level = 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 = ${openhab.logdir}/openhab.log
log4j2.appender.out.filePattern = ${openhab.logdir}/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 = ${openhab.logdir}/events.log
log4j2.appender.event.filePattern = ${openhab.logdir}/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 = 120MB

# Audit file appender
log4j2.appender.audit.type = RollingRandomAccessFile
log4j2.appender.audit.name = AUDIT
log4j2.appender.audit.fileName = ${openhab.logdir}/audit.log
log4j2.appender.audit.filePattern = ${openhab.logdir}/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_apache_sshd.level = WARN
log4j2.logger.org_apache_sshd.name = org.apache.sshd

Wolfgang_S · August 7, 2022, 3:47pm

smarthome ist he old instance name under 2.5 and was changed to openhab that is Hey your entries do not work.

Udo_Hartmann · August 7, 2022, 4:40pm

That’s the point. Please change org.ops4j.pax.logging.cfg to use the correct file (this is nowadays only a link to log4j2.xml)

Maybe make a backup for not to lose the old configuration.

Thomas_Kolbe · August 7, 2022, 4:41pm

Wolfgang, you’re the man!

That was the problem, now the events.log shows all item state changes. Means, taking a backup from OH2 into a fresh OH3 installation, brings that problem.

Thanks! Now I need to reduce log level of the specific bindings otherwise my PV-system completly floods my logs.

Cioa
Tom

Thomas_Kolbe · August 7, 2022, 4:42pm

Hi Udo,

as well thanks to you, but I’ll first keep it the way it is, because with Wolfgangs hint, it works as well the way it is at the moment.

Ciao
Tom

Udo_Hartmann · August 7, 2022, 4:44pm

Please ba aware that the xml file is the "new way for configuration and you will get into trouble if not using it on the long run

Thomas_Kolbe · August 7, 2022, 4:51pm

Ok, noted!

First I have to solve some other problems with my system, where I needed the logs for. Automatic lights and automatic rollershutter states for burglar protection with historic state, wich do not work.

Ciao
Tom