Rule debug possibility in logs changed with openHAB 3.4?

Two years ago I wrote a couple of rules (Javascript and RuleDSL) on openHAB 3.2 and 3.3, with the default openHAB logging settings printing out everything I needed to write & debug my rules. When something did not work, I received explicit information on what’s not working/ where things broke down.

I have the impression that on openHAB 3.4.4, things has changed:

  • logWarn (in Rule DSL) only worked again after I set log:set warn org.openhab.core.model.script (though logger.warn in JavaScript still doesn’t work).
  • Rules that don’t work due to a bug (JavaScript and RuleDSL) don’t show up with anything at all in the logs, independent from the log level I use (I tried out some, but no change).

Am I missing something? I’m using the default log level after a fresh 3.4.4 install.

Please check if all logger-config files are installed correct:

$OPENHAB_USERDATA/etc/log4j2.xml
$OPENHAB_USERDATA/etc/org.ops4j.pax.logging.cfg

The latter should have only one line of code:

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

So this is a link to the former file.

Check the content of the former file (maybe a diff to the original file from

1 Like

Of course so. When they don’t run - no matter what the reason for that is - the log statements are never executed. I doubt it has been different ever before.

My description was maybe not that clear. What I meant: Back then, when a rule got executed but stopped somewhere in the middle (e.g. because of syntax error) the log showed at least some hint. Right now, the log shows everything until the rule hits an error, and from there onwards, it does not show anything at all. That, if I’m not completely mistaken, used to be different.

Thanks a lot. tl;dr: You were right, my $OPENHAB_USERDATA/etc/log4j2.xml was messed up. I got it working again, and the log (again) nicely shows errors of rules.

Here’s what’s odd: My log4j2.xml was indeed messed up. Interestingly, in the same folder I had a file log4j2.xml.bak (which I definitely did not create myself), which contained a version of the file which got everything back to normal. Question is: How did this get there? A bug that should be reported?

The version that was activated (that did not work) looked the following.

<?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="OFF">
			<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 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>

		<!-- openHAB user based script logger configuration -->
		<Logger level="TRACE" name="org.openhab.automation.script"/>

		<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 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 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"/>
		<Logger name="org.openhab.binding.homematic"/>
		<Logger name="org.openhab.binding.homematic.internal.communicator.parser.GetParamsetParser"/>
		<Logger name="org.openhab.binding.zwave"/>
		<Logger name="org.openhab.core.io.transport.serial"/>
		<Logger name="org.openhab.binding.gardena.internal.GardenaSmartImpl"/>
		<Logger name="org.openhab.core"/>
		<Logger level="DEBUG" name="org.openhab.core.model.script"/>
	</Loggers>

</Configuration>