[SOLVED] Events.log flooding

Hi there,

I am currently trying to figure out how to tune down the logging intensity of my power meter.
I found an older post related to this subject (but refering to a different model/equipment):

event-log-flodding

In this post, there is a workaround suggested to prevent the logging mechanism of openHAB from logging specific events. For this, a custom filter was recommended to be added to the logging config in /var/lib/openhab2/etc/org.ops4j.pax.logging.cfg

In OH4, this file still exists as a one-line-referrer to an xml file in the same folder. My issue is that I don’t know how to register a custom filter in this xml structure.

This was the recommendation from the post as linked above:

There was a more root-cause-based recommendation, to configure the respective device at its core to tune down the update rate. For the Shelly EM3 which I am using, I searched the settings extensively and also other websites for solutions on that matter. I found the API documentation and something that pointed toward an update interval which I even could change, but it had no effect, my events.log gets flooded with fraction changes on Watt numbers every second for three power lines.

Another tip was to remove the according channels from the openhab thing config. That wouldn’t be the preferred approach for me as I still want to monitor the power data, just not on that granularity and with such a high update interval. I use the persistence config to just store the values once every couple of minutes.

Can anyone help me in solving the events.log symptom? How I can register a custom filter in the logging config that supresses the following log entries?

2023-08-31 10:37:15.327 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_1' changed from -124.16 W to -133.93 W
2023-08-31 10:37:15.335 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_2' changed from 94.58 W to 82.15 W
2023-08-31 10:37:15.340 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_3' changed from 114.66 W to 97.93 W
2023-08-31 10:37:17.549 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_1' changed from -133.93 W to -133.8 W
2023-08-31 10:37:17.555 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_2' changed from 82.15 W to 81.13 W
2023-08-31 10:37:17.560 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'shellyem38caab561eed3__1721666236_Power_Consumption_3' changed from 97.93 W to 109.52 W
  • Platform information:
    • Hardware: Intel® Celeron® CPU J1900 @ 1.99GHz
    • OS: Unraid virtual environment - Debian VM running Debian 12
    • Java Runtime Environment: OpenJDK Runtime Environment (build 17.0.8+7-Debian-1deb12u1)
    • openHAB version: openHAB 4.0.2

https://logging.apache.org/log4j/log4j-2.2/manual/filters.html#RegexFilter

If the channel doesn’t let you configure this you might be able to do something in a profile. I think the smarthome/j add-on marketplace has a profile for this but with native OH profiles you’d need to use a transform profile. Create a JS transform under Settings → Transformations along the lines of this:

(function(data) {
  const THRESHOLD = 0.5;
  const lastValue = parseFloat(cache.private.get('last'));
  const currValue = parseFloat(data);

  if(lastValue === null 
     || Math.abs(currValue - lastValue) >= THRESHOLD) {
    cache.private.put('last', currValue);
    return data;
  }
  
  return cache.private.get('last');

})(input)

The value will have to change at least 0.5 from the last returned value before it will return a new value. The Item will still get updated but it won’t change.

The same approach can be used with a timestamp to base it on time instead of the magnitude of the change.

see here

Thanks for this idea, I thought to try it this way first before potentially considering the regex filter approach.

After reading a tutorial on how-to-use-transformations and then some further research (due to slight changes between OH3 and OH4 as I understand, I could finally make it work. Thanks again so much for the code, it would have taken me quite some time to figure it out on my own.

As you instructed, I registered the code as a transformation in Settings → Transformations. Tranformation Type “JS”.
Saved that and then went to the according thing. Under Channels, I selected the channel and clicked on the linked item.
There I selected “SCRIPT ECMAScript (ECMAScript 262 Edition 11)” which seems to represent the former JS profile name (which was much easier to comprehend :wink: ).
Then select the script in the “thing to item transformation” and good-to-go :slight_smile:

P.S: I had to alter the code slightly. The if clause needs to trigger true for the last value being null. I therefore changed to check the cache.private.get(‘last’) directly. parseFloat apparently returns a NaN if the input value is null, therefore the if check didn’t trigger.

(function(data) {
   
    const THRESHOLD = 50;
    const lastValue = parseFloat(cache.private.get('last'));
    const currValue = parseFloat(data);
   
  if(cache.private.get('last') === null 
     || Math.abs(currValue - lastValue) >= THRESHOLD) {
    cache.private.put('last', currValue);
    return data;
  }
  return cache.private.get('last');
})(input)

Now, the transformation function is working as a charm if being used for exactly one item.
When I use the same function for various items, it stops working because the last value seems to be the value of whatever item the function parsed before the current iteration.
Therefore, on my end, the if clause always triggers because the difference between value of item#2 and value of item#1 is always > THRESHOLD.

Any idea what I have to change to correct that behavior? Dirty workaround would be to duplicate the transformation function for each item but then I would have a full redundancy and not a nice and clean approach.
I wonder if I somehow can catch the item name in the function? Then I could use an array in the transformation function to register every item for which the function gets called and store their last values there.

If that’s not possible to solve natively, I probably should consider switching to a regex filter after all…

If you just had one JS add-on installed it works just say “JS”. But you have both so there has to be a way to distinguish between the two.

That is unexpected. It is using the private cache. It must reuse the transform instance across rules instead of creating a separate insurance per rule.

This can be overcome.

I don’t think event is defined in a transform but it might be. In that case replace the string 'last' with event.itemName. You don’t need an array or anything else. The cache will keep them separated.

If there is no event, you can pass arguments to the transform by appending it to the config config:js:damploggingextend?lastkey=<something unique> where <something unique> is the name of the item or something else unique to this profile. Then replace 'last' with lastKey (no quotes).

As you suspected:
2023-09-01 19:32:45.212 [ERROR] [.module.script.profile.ScriptProfile] - Failed to process script ‘config:js:damploggingextend’: org.graalvm.polyglot.PolyglotException: ReferenceError: “event” is not defined

Will try with the argument now.

This did the trick!! :smiley:

And as I learned from a different post from you, I used console.log statements for debug reasons, below the result can be seen. no catch is the else path in the code (changes ignored and not logged in events.log), the other one is the if(true) case. I will tune the threshold a bit more and probably make it an argument as well, so that I can use different thresholds for different use cases.

2023-09-01 19:44:34.487 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 41.75
2023-09-01 19:44:34.493 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 112.02 - 111.68
2023-09-01 19:44:35.137 [INFO ] [org.openhab.automation.script       ] - owbpc::Catch! currvalue=384, lastValue=341: diff was: 43
2023-09-01 19:44:35.442 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -126.75
2023-09-01 19:44:35.444 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 43.23
2023-09-01 19:44:35.447 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 112.02 - 124.09
2023-09-01 19:44:37.441 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -125.07
2023-09-01 19:44:37.443 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 44.69
2023-09-01 19:44:37.446 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 112.02 - 114.47
2023-09-01 19:44:37.546 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -125.07
2023-09-01 19:44:37.550 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 44.69
2023-09-01 19:44:37.554 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 112.02 - 114.47
2023-09-01 19:44:38.438 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -126.02
2023-09-01 19:44:38.441 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 43.95
2023-09-01 19:44:38.444 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 112.02 - 130.49
2023-09-01 19:44:40.603 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -127.48
2023-09-01 19:44:40.608 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 43.61
2023-09-01 19:44:40.611 [INFO ] [org.openhab.automation.script       ] - hpc3::Catch! currvalue=135.35, lastValue=112.02: diff was: 23.33
2023-09-01 19:44:42.435 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -122.68
2023-09-01 19:44:42.438 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 47.1
2023-09-01 19:44:42.440 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 135.35 - 134.7
2023-09-01 19:44:43.435 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -122.2
2023-09-01 19:44:43.438 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 49.27
2023-09-01 19:44:43.440 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 135.35 - 122
2023-09-01 19:44:43.659 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -122.2
2023-09-01 19:44:43.663 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 49.27
2023-09-01 19:44:43.667 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 135.35 - 122
2023-09-01 19:44:44.438 [INFO ] [org.openhab.automation.script       ] - hpc1::no catch: values: -117.72 - -124.49
2023-09-01 19:44:44.441 [INFO ] [org.openhab.automation.script       ] - hpc2::no catch: values: 35.22 - 33.14
2023-09-01 19:44:44.443 [INFO ] [org.openhab.automation.script       ] - hpc3::no catch: values: 135.35 - 136.57
2023-09-01 19:44:45.231 [INFO ] [org.openhab.automation.script       ] - owbpc::no catch: values: 384 - 367

I really really thank you for your continuous support and for investing precious time to help out other users here. Greatly appreciated!

1 Like

use & between the arguments if there is more than one, just like you see with web pages. More details and examples are in the JS Scripting add-on docs.