Log4j2 Sample Config

Check your capitalization as compared with the one in the toubleshooting doc,

log4j2.logger.Zwave.name = org.openhab.binding.zwave
log4j2.logger.Zwave.level = DEBUG
log4j2.logger.Zwave.additivity = false
log4j2.logger.Zwave.appenderRefs = Zwave
log4j2.logger.Zwave.appenderRef.Zwave.ref = ZWAVE
1 Like

thanks mark!! I used an example from this thread, which was wrong

Thank you all my logging files are now reduced from a wild torrent into a static lake.
Even understand how to re-open the flow or add missing statement; to be honest just an ordinary TECP
Thinks this method might be even mentioned at this point of the documentation (but in this case leave this discusion to the experts).

Can now concentrate on a error which was lost in the waves:

[ERROR] [org.eclipse.lsp4j.jsonrpc.RemoteEndpoint          ] - Internal error: java.lang.IllegalArgumentException: URI has an authority component

But this is off topic so not asking to investigate this error, but sharing a know solution is off course very much welcome.

Solved: My URI ERROR was caused by settings of VSCode + Openhab extension see further post. Hope this is helpfull.

Hi all,

I’ve installed the Spotify Connect binding and it logs the song progress every second, so I would like to set the binding to WARN level.

So I updated the org.ops4j.pax.logging.cfg with these lines at the bottom:

# Custom Log Levels
log4j2.logger.org_openhab_binding_spotify.name = org.openhab.binding.spotify
log4j2.logger.org_openhab_binding_spotify.level = WARN

The binding however still logs the output every second (frontail)

Is there something I’m missing?

My Pi is running headless so I don’t think I can run Karaf to set the log levels there.

Thanks in advance

The binding isn’t logging that every second. You are looking at events.log. events.log is the EventBus’s log. It logs all events that get put on the EventBus (except for updates). The song progress Item is changing every second so that get’s logged to events.log. There is a way to filter out those lines from the events.log using openHAB - Filtering event logs. However, IMHO, you may as well just turn off events.log before neutering it by selectively filtering out events. Either it’s a log of the events or it’s not.

Once again a quality answer, thank you Rich.

openHAB - Filtering event logs looks like it will do the trick.

Is it possible to use something from the openhab.log in a rule to send me a message one this particular event occurs?
It´s a WARN message and not a item change in the events.log

kind regards
Michael

Take a look at the logreader binding.

1 Like

Thanks Mark!
I searched anywhere but not for a binding :smiley:

Hey there =)

I am having issues with setting up the configuration file so that only some bindings show their log entries. Currently my log looks something like this

2020-03-29 19:06:50.556 [vent.ItemStateChangedEvent] - NanoleafBrightness changed from 0 to 100
2020-03-29 19:06:51.391 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 23.0 to 24.0
2020-03-29 19:06:52.448 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 24.0 to 22.0
2020-03-29 19:06:53.517 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 22.0 to 23.0
2020-03-29 19:06:54.593 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 23.0 to 34.0
2020-03-29 19:06:55.649 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 34.0 to 22.0
2020-03-29 19:06:56.760 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 22.0 to 67.0
2020-03-29 19:06:57.801 [vent.ItemStateChangedEvent] - LatencyAsterix changed from 67.0 to 18.0
2020-03-29 19:06:58.808 [vent.ItemStateChangedEvent] - RasperryMemoryUsed changed from 747 to 746

In this example you can see that the network binding produces many entries. So I want to mute it. I tried to copy the configuration of the first entry but it didnt seem to work.

If i enter

log4j2.logger.smarthome_event_ItemStateChangedEvent.name = smarthome.event.ItemStateChangedEvent
log4j2.logger.smarthome_event_ItemStateChangedEvent.level = WARN

in the config file all ItemStateChangedEvents dont show up. However I didnt manage to muti only some bindings. I tried

log4j2.logger.org_openhab_binding_network.level = WARN
log4j2.logger.org_openhab_binding_network.name = org.openhab.binding.network

However this didnt change anything.

I want to mute the Spotify and the network binding. Can someone please show me how the configuration has to look like.

Thanks!

The example is showing ItemStateChangedEvent , I think these are logged by openHAB core (the event bus) not the binding, rule, or UI that caused the event.

Tinkering with binding logging therefore will not affect that.

What problems does this cause you?

Yes you’re right.
My question is if I can deactivate those ItemStateChangedEvent entries for some bindings. So for example I want to get the ItemStateChangedEvent entries from my weather binding and want to not get the ItemStateChangedEvent for the network or the spotify binding.

By now I understand why this didnt help me.

Do you understand my question and what I am trying to accomplish?

No, because they are events on the event bus, whatever source put them there. The binding is not involved in this logging.

Yes, but I’ve no idea why you want to do it. What terrible pain does it cause you?

You could maybe look at this post above for suppression by keyword, perhaps you missed it

This was exacly was I looking for :heart_eyes:

For creating the regex you can use a site like this https://www.regextester.com/

log4j2.appender.event.filter.regex.type = RegexFilter
log4j2.appender.event.filter.regex.regex = .* (Latency|TrackProgress|Liedfortschritt).*
log4j2.appender.event.filter.regex.onMatch = DENY
log4j2.appender.event.filter.regex.onMisMatch = ACCEPT

Hi, very helpful discussion here.

Continuing the same topic with a specific twist.

I have a openhab with rules on jython. And I find it a bit frustrating, that I need to actively look for errors in several logs files I have.

Can we come up with some appender configuration, which would filter only failure and error related messages? I would like to have this appender create a file per day, so then it would be very easy to see if my system was producing any errors that day.

So basically selecting parts of texts which were originated by errors, exceptions, failures etc. And it would be great not only to select only the line, but all the relevant text, like this:

13:01:27.902 [ERROR] [sr223.jython.Heating NORMAL schedule] - Traceback (most recent call last):
File “/etc/openhab2/automation/lib/python/core/log.py”, line 51, in wrapper
return fn(*args, **kwargs)
File “”, line 169, in heating_load_new_targets
File “”, line 58, in orchestrate
File “”, line 108, in load_d_variables
KeyError: ‘vars’

Well, the first question is why do you have multiple files to look through? If having them in multiple files is a problem, put them into one file. By default you would only have two log files, openhab.log and events.log and errors and warnings never appear in events.log.

For one, that’s not how log4j works. It doesn’t save up stuff and produce a file at the end of the day. When a log statement occurs, it gets written out.

Secondly, log4j works by giving each part of the code, libraries, your Rules, bindings, stuff in the core, it’s own log name. Then you can configure what gets actually written out where based on log level. It is possible to create a filter for a given logger to suppress certain log statements.

Therefore, to achieve what you are after and to preserve the logs as they exist now you basically need to do a copy/paste/edit of the entire log4j config and create a separate appender and set them up to additionally log out to this new appender just errors and warnings.

But in order to understand a given error you often need the context that is logged out at the INFO or DEBUG level immediately before the error. I don’t see how this could do anything but make it harder to debug a problem.

If all you want is to know whether or not errors occurred: grep 'ERROR\|WARN' openhab.log will give you a list of all the errors. You could create a cron job that runs grep 'ERROR\|WARN' | count and curls that to an OH Item every night. That’s the “number of errors previous day” count. When it’s not zero you know you have a problem to debug, open openhab.log and search for the ERROR. Then you get to see the error in context and from there solve it.

Your proposal would result in just yet another file you will need to look at and search through in order to find errors.

Hi,
I am trying to limit the logging for some bindings but I am not successful.
openHAB 2.5.2-1 (Release Build)

adding the following lines to
/var/lib/openhab2/etc/org.ops4j.pax.logging.cfg:

# Custom Log Levels
log4j2.logger.org_openhab_binding_ntp.name = org.openhab.binding.ntp
log4j2.logger.org_openhab_binding_ntp.level = WARN
log4j2.logger.org_openhab_binding_network.name = org.openhab.binding.network
log4j2.logger.org_openhab_binding_network.level = WARN
log4j2.logger.org_openhab_binding_fritzboxtr064.name = org.openhab.binding.fritzboxtr064
log4j2.logger.org_openhab_binding_fritzboxtr064.level = WARN

Unfortunately nothing happens, the log throws line after line in the events.log, example:

2020-05-07 18:36:19.600 [vent.ItemStateChangedEvent] - FritzboxUptime changed from 5290088 to 5290151

2020-05-07 18:36:19.694 [vent.ItemStateChangedEvent] - Heute changed from 2020-05-07T18:36:04.663+0200 to 2020-05-07T18:36:19.669+0200

2020-05-07 18:36:19.696 [vent.ItemStateChangedEvent] - ntp_ntp_zeit_string changed from 2020-05-07 18:36:04 CEST to 2020-05-07 18:36:19 CEST

2020-05-07 18:36:31.634 [vent.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2020-05-07T18:35:31.606+0200 to 2020-05-07T18:36:31.611+0200

2020-05-07 18:36:31.637 [vent.ItemStateChangedEvent] - ntp_ntp_local_string changed from 2020-05-07 18:35:31 CEST to 2020-05-07 18:36:31 CEST

2020-05-07 18:36:34.695 [vent.ItemStateChangedEvent] - Heute changed from 2020-05-07T18:36:19.669+0200 to 2020-05-07T18:36:34.672+0200

2020-05-07 18:36:34.698 [vent.ItemStateChangedEvent] - ntp_ntp_zeit_string changed from 2020-05-07 18:36:19 CEST to 2020-05-07 18:36:34 CEST

2020-05-07 18:36:37.192 [vent.ItemStateChangedEvent] - network_pingdevice_192_*_*_*_latency changed from 15.0 ms to 315.0 ms

2020-05-07 18:36:37.287 [vent.ItemStateChangedEvent] - network_pingdevice_192_*_*_*_lastseen changed from 2020-05-07T18:35:36.823+0200 to 2020-05-07T18:36:37.253+0200

These entries appear any few seconds, for every change triggered (what I do not need to know at this level, of course).
Any idea what I am missing here?
Thanks a lot!
Andreas

events.log is generated by the event bus, not by individual bindings. Changing the logging level of the binding does nothing for that.

Frankly, I’m of the opinion that events.log should either be kept whole and use the tools available to you to only look at those lines that are relevant at a given time or turn off events.log entirely. But if you must, see openHAB - Filtering event logs to filter events.log.

I have a lot of ItemStateChangedEvent because of my power meter plug. This is updating ever few seconds.
Is there a possibility to ignore the ItemStateChangedEvents just for a specific Item? Or can it only ignored for all Items or none?

The post literally right above this one has your answer. Hint, look at the link “Filtering event logs”.