openHAB - Filtering event logs

woernsn · November 16, 2023, 2:09pm

I also just played around with filters, thanks a lot for this helpful post!
While doing some playing around, I found a way to better organize multiple RegexFilters without concatenating them with OR.

			<Filters>
				<RegexFilter regex=".*Systeminfo_.*" onMatch="DENY" onMismatch="NEUTRAL"/>
				<RegexFilter regex=".*CPUUtilization_.*" onMatch="DENY" onMismatch="NEUTRAL"/>
				<RegexFilter regex=".*Nightscout_.*" onMatch="DENY" onMismatch="NEUTRAL"/>
			</Filters>

By wrapping RegexFilters inside the Filters tag, they can be combined.
Note that the onMismatch has to be set to NEUTRAL. If set to ACCEPT, the other filters will be skipped.

rpwong · November 17, 2023, 6:02am

Thanks, this works great.

To add a little more detail, everything between <Filters></Filters> can directly replace the single <RegexFilter> line in the event log appender.

Nice having the ability to add comments on the various filters, and to add/remove individual lines when troubleshooting.

Python · November 17, 2023, 1:33pm

After modifying log4j.xml to add a filter, does it require a restart for the changes to take effect?

rpwong · November 17, 2023, 6:00pm

No, it picks up the change within a minute or so.

witek_1308 · February 13, 2024, 8:03pm

Hey,
I’m on 4.1.0 and trying to filter out from events.log all item updates and state changes with the prefixes of EBUS and Vaillant but can’t get this to work. I finally focused on just Vaillant for the moment as below:

2024-02-13 20:53:17.791 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_tempDFlow_FlowTemperatureTargetValueOrReturnTargetValue' updated to 29.5
2024-02-13 20:53:22.490 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_ServiceWaterReturnTemperature' updated to 47
2024-02-13 20:53:22.491 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterReturnTemperature' updated to 27
2024-02-13 20:53:22.493 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterTemperature' updated to 28.5
2024-02-13 20:53:25.331 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_ServiceWaterReturnTemperature' updated to 47
2024-02-13 20:53:25.332 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterReturnTemperature' updated to 27
2024-02-13 20:53:25.333 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterTemperature' updated to 28.5
2024-02-13 20:53:32.561 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_ServiceWaterReturnTemperature' updated to 47
2024-02-13 20:53:32.563 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterReturnTemperature' updated to 27
2024-02-13 20:53:32.565 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantBAI0008_Bai_boiler_control_getopdata_LeadWaterTemperature' updated to 28.5
2024-02-13 20:53:35.580 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'VaillantVRC470Time' updated to 2024-02-13T20:54:41.000+0100
2024-02-13 20:53:35.581 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'VaillantVRC470Time' changed from 2024-02-13T20:53:41.000+0100 to 2024-02-13T20:54:41.000+0100

My file /var/lib/openhab/etc/org.ops4j.pax.logging.cfg looks like that (snippet), I copied examples from above and adapted to my case. Can paste whole if it matters:

# 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 = 16MB

# 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 = *

############ CUSTOM FILTERS START HERE #################
log4j2.appender.event.filter.stuff.type = Filters

log4j2.appender.event.filter.stuff.ebus.type = RegexFilter
log4j2.appender.event.filter.stuff.ebus.regex = .*Vaillant.*
log4j2.appender.event.filter.stuff.ebus.onMatch = DENY
log4j2.appender.event.filter.stuff.ebus.onMismatch = NEUTRAL

################# END OF FILTERS ######################

I restarted OH to avoid doubts that it didn’t pick up the config change.
Is my filter screwed or it makes a difference where exactly in the file it sits or yet else?

rpwong · February 13, 2024, 8:24pm

It appears that you’ve used the example from the first post, which was written for OH2 over six years ago. Per the discussion, it does not work in OH3 (or OH4). You need this:

And if you want to have multiple filters, you can use this.

witek_1308 · February 13, 2024, 8:44pm

right! it works! Don’t know why/how I missed it thanks @rpwong

Python · February 14, 2024, 1:30am

Is there a trick to get it to block multi-line logs in events.log?

log4j2.xml:

                <!-- Event log appender -->
                <RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i.gz" name="EVENT">
                        <RegexFilter regex=".*LastEventData.*" onMatch="DENY" onMismatch="ACCEPT"/>
                        <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
                        <!-- <RegexFilter regex="(?<=EventNotificationAlert version)(?s).*(?=EventNotificationAlert)" onMatch="DENY" onMismatch="NEUTRAL"/> -->
                        <Policies>
                                <OnStartupTriggeringPolicy/>
                                <SizeBasedTriggeringPolicy size="16 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="7"/>
                </RollingRandomAccessFile>

For instance i can’t ever get it to hide this line:

2024-02-13 20:27:07.953 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'CAMERA_FrontYard_LastEventData' changed from <EventNotificationAlert version="2.0" xmlns="http://www.hikvision.com/ver20/XMLSchema">
<ipAddress>192.168.3.201</ipAddress>
<ipv6Address>::</ipv6Address>
<portNo>80</portNo>
<protocol>HTTP</protocol>
<macAddress>4c:f5:dc:4b:7d:f4</macAddress>
<channelID>1</channelID>
<dateTime>2024-02-13T20:26:56+08:00</dateTime>
<activePostCount>1</activePostCount>
<eventType>videoloss</eventType>
<eventState>inactive</eventState>
<eventDescription>videoloss alarm</eventDescription>
<channelName>Front Yard</channelName>
<Extensions>
<serialNumber>DS-2CD2347G2-</serialNumber>
<eventPush>DS-2CD2347G2-,2024-02-13T20:26:56+08:00,0,1.0</eventPush>
</Extensions>
</EventNotificationAlert>
 to <EventNotificationAlert version="2.0" xmlns="http://www.hikvision.com/ver20/XMLSchema">
<ipAddress>192.168.3.201</ipAddress>
<ipv6Address>::</ipv6Address>
<portNo>80</portNo>
<protocol>HTTP</protocol>
<macAddress>4c:f5:dc:4b:7d:f4</macAddress>
<channelID>1</channelID>
<dateTime>2024-02-13T20:27:06+08:00</dateTime>
<activePostCount>1</activePostCount>
<eventType>videoloss</eventType>
<eventState>inactive</eventState>
<eventDescription>videoloss alarm</eventDescription>
<channelName>Front Yard</channelName>
<Extensions>
<serialNumber>DS-2CD2347G2-</serialNumber>
<eventPush>DS-2CD2347G2-,2024-02-13T20:27:06+08:00,0,1.0</eventPush>
</Extensions>
</EventNotificationAlert>

JimT · February 14, 2024, 1:40am

Why not filtering it out when reading the log, rather than preventing the data from being written?

Python · February 14, 2024, 2:00am

14 camers spamming that change causes the logs to roll over every 40mins. It looks like i might of found the solution.

<RegexFilter regex="(?s).*LastEventData.*" onMatch="DENY" onMismatch="ACCEPT"/>