Filtering Logs using regex OH3

Mr-JR · August 26, 2021, 8:15pm

I’m trying to follow the docs on adding a filter. Perhaps there is another way to do this, but I want to filter out the Item updates for:

2021-08-26 13:01:57.051 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'PresenceJames_LastSeen' changed from 2021-08-26T13:00:51.473-0700 to 2021-08-26T13:01:57.044-0700

I modified my userdata/etc/log4j2.xml file and and at the appropriate place, added:

 <RegexFilter regex=".*(PresenceJames_LastSeen).*" onMatch="DENY" onMismatch="ACCEPT"/>

Here is the relevant section of the docs:

The configuration format of openHAB 3.0 is in xml format.

* Open the file `userdata/etc/log4j2.xml`
* Search for tag RollingFile
* and add a tag `<RegexF,ilter>...</RegExFilter>`

The attribute `regex` of this tag defines the regular expression, `onMatch="DENY"` the the logger to discard those lines

Example:

        <!-- Rolling file appender -->
        <RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i" name="LOGFILE">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
            <RegexFilter regex=".*(heartBeat|LastUpdate|lastUpdate|LetzteAktualisierung|Uptime|Laufzeit|ZuletztGesehen).*" onMatch="DENY" onMismatch="ACCEPT"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="16 MB"/>
            </Policies>
        </RollingFile>

What am I missing? I did not reboot or stop/start openhabian (not sure if necessary).

apella12 · August 26, 2021, 9:05pm

I’m not an expert and it has been a while, but I think you need to restart OH for the changes to take place.

Bob

Mr-JR · August 26, 2021, 9:07pm

Ok, I’ll give that a shot … but that would certainly make debugging the regex quite slow … my system takes 30-45 minutes to come back to normal (mostly zigbee devices restoring) … hopefully thats not the right answer

Andrew_Pawelski · August 26, 2021, 11:58pm

@Mr-JR how did you go? - im keen to hear if this works - i have some noise in logs Id love to get rid of

Mr-JR · August 27, 2021, 12:00am

Unfortunately it has to wait … I cant take the system down until tomorrow morning

Spaceman_Spiff · August 27, 2021, 3:44am

Changing to the logging configuration get picked up without a restart.
This can be easily tested by setting a logger to “DEBUG” instead of “INFO”.

apella12 · August 27, 2021, 1:44pm

I have set a logger in the console between levels without a restart and saw immediate change, no problem. However, when I edited log4j2.xml file directly (like above) to add a regenx filter and to create a separate log file for zwave, I dimly recall the filtering did not start or the separate zwave log file was not created until after a restart. Maybe I needed to change the logger level in the console just to get the xml file reread. Anyway it sounds like James R edits did not start working for him, so I was just making a suggestion based on my limited experience.

Bob

Mr-JR · August 27, 2021, 4:36pm

Ok. I rebooted my system after adding the line:

<RegexFilter regex=".*(PresenceJames_LastSeen).*" onMatch="DENY" onMismatch="ACCEPT"/>

to the file: openhab-userdata/etc/log4j2.xml

Unfortunately, it did not do the filter. What am I missing? Has anyone made this work?

JustinG · August 27, 2021, 5:39pm

If I understand what you have posted, you now have two RegexFilters in your RollingFile. I think your problem may be the way you are stacking those filters. The ACCEPT and DENY for the onMatch and onMismatch, I believe, end the searching so your second filter is never even being called. Instead, you need the first filter to passthrough (NEUTRAL) to the second filter if it is not blocking the line so I think you need to modify the first filter to be:

<RegexFilter regex=".*(heartBeat|LastUpdate|lastUpdate|LetzteAktualisierung|Uptime|Laufzeit|ZuletztGesehen).*" onMatch="DENY" onMismatch="NEUTRAL"/>

and keep the ACCEPT as the result only if the line passes the second filter too.

Mr-JR · August 27, 2021, 6:07pm

No, you are referring to the documentation example. My file has only the single line:

<RegexFilter regex=".*(PresenceJames_LastSeen).*" onMatch="DENY" onMismatch="ACCEPT"/>

Mark_VG · August 27, 2021, 7:01pm

Hi

This is what I used:

<RegexFilter onMatch="DENY" onMismatch="NEUTRAL" regex=".*(Pin_Number).*"/>

This filters anything with Pin_Number from the logs.

Positioned in the Event Log appender:

		<!-- Event log appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i" name="EVENT">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
		<!-- Filter Pin Number from Logs -->	
		<RegexFilter onMatch="DENY" onMismatch="NEUTRAL" regex=".*(Pin_Number).*"/>	
			<Policies>
				<OnStartupTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="16 MB"/>
			</Policies>
		</RollingRandomAccessFile>

Mr-JR · August 27, 2021, 8:12pm

Thanks for the suggestion, tried that but obviously I have something else wrong … is there a way to debug the log itself?

JustinG · August 27, 2021, 11:09pm

Perhaps at this point we might be able to offer more specific advice if you posted the entire contents of the log4j2.xml file.

Also, have you triple checked that you are editing the correct version of the file? I know it seems obvious, but sillier things have happened.

Mr-JR · August 27, 2021, 11:18pm

My original post has all the details. I am modifying the existing file with that one line added. Here’s the entire file:

<?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" name="LOGFILE">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
		<RegexFilter onMatch="DENY" onMismatch="NEUTRAL" regex=".*(PresenceJames_LastSeen).*"/>	
			<Policies>
				<OnStartupTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="16 MB"/>
			</Policies>
		</RollingFile>

		<!-- Event log appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i" 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>
		</RollingRandomAccessFile>

		<!-- Audit file appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/audit.log" filePattern="${sys:openhab.logdir}/audit.log.%i" 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>
		</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.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 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="WARN" name="org.apache.sshd"/>
		<Logger level="WARN" name="org.openhab.binding.hue"/>
		<Logger level="WARN" name="org.openhab.binding.zwave"/>
		<Logger level="WARN" name="org.openhab.binding.zigbee"/>
		<Logger level="WARN" name="com.zsmartsystems.zigbee"/>
		<Logger level="INFO" name="org.openhab.core.model.script.kitchen"/>
		<Logger level="INFO" name="org.openhab.core.model.script.TimerDemo"/>
		<Logger level="INFO" name="org.openhab.core.model.script.Hall_Bath"/>
		<Logger level="WARN" name="org.openhab.core.automation"/>
		<Logger level="DEBUG" name="jsr223"/>
		<!-- JRER Filters known issues of Chromecast -->
        <Logger level="ERROR" name="su.litvak.chromecast.api.v2.Channel"/>
        <Logger level="DEBUG" name="org.eclipse.smarthome.model.script"/>
        <Logger level="OFF" name="com.zsmartsystems.zigbee.dongle.ember.internal.ash"/>
	</Loggers>

</Configuration>

This was copy pasted from cat /srv/openhab-userdata/etc/log4j2.xml

Mr-JR · October 8, 2021, 3:08pm

re-upping this … would really be interested in anyone that has this working with OH3

Mark_VG · October 8, 2021, 3:23pm

When I initially had issues with this I found that my log4j2.xml file seemed to be corrupt. I was battling to set any logging levels etc.

So I downloaded the latest from GitHUB and then worked from there and all seemed to start working again.

Other test to confirm that you are editing the correct file would be to check the current logging levels and then remove the following lines:

         <Logger level="DEBUG" name="org.eclipse.smarthome.model.script"/>
        <Logger level="OFF" name="com.zsmartsystems.zigbee.dongle.ember.internal.ash"/>

Which seem to be custom logging levels.

Then check what the new logging levels are?
Here is my working file with a REGEX filter

log4j2.xml-working shelly and gpstracker.txt (6.9 KB)

Mr-JR · October 8, 2021, 3:36pm

Thanks Mark. Good suggestion. I looked at my log4j2.xml and confirmed that changing a log level (through sudo openhab-cli console) did indeed result in the log4j2.xml being updated. So that confirms I am modifying the right file.

I’ll study your working example for hints. thanks!

Mr-JR · October 8, 2021, 3:49pm

Ok, I found it. The docs are wrong, your file is correct. The answer is that the regex line should be in the
 section, and not in the  section …

I guess I should file a PR to update the docs?