Rule execution lags, possibly Java GC

@mstormi

1) Albeit I don’t think it would make a difference, any reason not to try -XX:+UseParallelGC ?
You may have missed my post above (linked below). The -XX:+UseParallelGC option caused my Openhab to never actually start. My testing/conclusion is in this post.
https://community.openhab.org/t/8-seconds-lag-always-after-few-minutes-without-script-activation/93882/47?u=ewrw

2) Did you change -Xms meanwhile ? Ran this in addition to those new -XX ?
Which -Xms and -Xmx do you actually use ?

Im not using anything else, so my EXTRA_JAVA_OPTS looks like this currently

EXTRA_JAVA_OPTS="-XX:-UseAdaptiveSizePolicy -XX:+UseParNewGC -XX:InitiatingHeapOccupancyPercent=95 -XX:MinHeapFreeRatio=15 -XX:MaxHeapFreeRatio=30 -XX:+UseCodeCacheFlushing"

3) BTW how did you determine the delay? Differences in events.log only?
Can you insert specific logging at the beginning of your rule and correlate that with the button press in event.log, please.
On my 1st post on here, I got the 22 second delay info from MQTT Browser showing the press of the button and then the MQTT response:
https://community.openhab.org/t/8-seconds-lag-always-after-few-minutes-without-script-activation/93882/29?u=ewrw

On another post, part way through the Java options, this is an event log, showing a 13 second delay, with RFDataLights changed from NULLFORTESTING to 3D1301 being the button press.

2020-04-29 20:10:43.743 [vent.ItemStateChangedEvent] - RFDataLights changed from NULLFORTESTING to 3D1301
2020-04-29 20:10:56.670 [vent.ItemStateChangedEvent] - Current_DateTime changed from 2020-04-29T20:09:56.642+0100 to 2020-04-29T20:10:56.649+0100
2020-04-29 20:10:56.913 [ome.event.ItemCommandEvent] - Item 'gBedroom1' received command ON
2020-04-29 20:10:56.940 [ome.event.ItemCommandEvent] - Item 'lsBed1' received command ON
2020-04-29 20:10:56.954 [ome.event.ItemCommandEvent] - Item 'lsBed1a' received command ON
2020-04-29 20:10:56.961 [vent.ItemStateChangedEvent] - RFDataLights changed from 3D1301 to NULLFORTESTING
2020-04-29 20:10:56.964 [nt.ItemStatePredictedEvent] - lsBed1 predicted to become ON
2020-04-29 20:10:56.977 [nt.ItemStatePredictedEvent] - lsBed1a predicted to become ON
2020-04-29 20:10:56.992 [vent.ItemStateChangedEvent] - lsBed1 changed from OFF to ON
2020-04-29 20:10:56.994 [vent.ItemStateChangedEvent] - lsBed1a changed from OFF to ON

On my post 2 posts up, I have another sample from the event log, with a similar result:

2020-05-02 10:14:21.201 [vent.ItemStateChangedEvent] - RFDataLights changed from NULLFORTESTING to 811301
2020-05-02 10:14:33.634 [ome.event.ItemCommandEvent] - Item 'gUpstairs' received command ON
2020-05-02 10:14:33.677 [ome.event.ItemCommandEvent] - Item 'lsDesk' received command ON
2020-05-02 10:14:33.716 [ome.event.ItemCommandEvent] - Item 'lsWillow' received command ON
2020-05-02 10:14:33.718 [vent.ItemStateChangedEvent] - RFDataLights changed from 811301 to NULLFORTESTING
2020-05-02 10:14:33.720 [nt.ItemStatePredictedEvent] - lsDesk predicted to become ON
2020-05-02 10:14:33.757 [nt.ItemStatePredictedEvent] - lsWillow predicted to become ON
2020-05-02 10:14:33.774 [vent.ItemStateChangedEvent] - lsDesk changed from OFF to ON
2020-05-02 10:14:33.787 [vent.ItemStateChangedEvent] - lsWillow changed from OFF to ON

The rule I have, changes RFDataLights, back to “NULLFORTESTING” so that I always know that variable is changed to a new variable and therefore logged each time its used by a device.

Im assuming you want me to ADD these new options onto the Java EXTRA_JAVA_OPTS that I have… I will read the document you sent, get that set up… I will get you a recording with and without the extreme options… Give me a few more days!!

Thanks :slight_smile: