Hi,
I’m taking the first baby steps towards migrating my DSL rules to JavaScript. Unfortunately I’m starting to see a pattern: Every time I edit and trigger a rule a few times, my system becomes very unstable and runs out of Java heap space. I’m running openHABian:
openhabian@openHABianPi:/etc/openhab $ uname -a
Linux openHABianPi 4.19.66-v7+ #1253 SMP Thu Aug 15 11:49:46 BST 2019 armv7l GNU/Linux
on a Raspberry Pi 3 with openHAB 3.2.
So far I have only one rule:
/etc/openhab/automation/js/test.js:
rules.JSRule({
name: "Danfoss boost new",
description: "Push notification when boost is triggered on Danfoss Air",
triggers: [triggers.ItemStateChangeTrigger('Test', 'OFF', 'ON')],
execute: data => {
var item = items.getItem("DanfossHRV_Humidity");
var danfossRecentHumidity = item.history.historicState(time.ZonedDateTime.now().minusMinutes(22));
var body = "Boost er aktiveret. Luftfugtighed: ${danfossRecentHumidity} %";
console.log(body);
}
});
After editing and triggering this rule just a few times, this happened:
2021-12-29 14:28:55.620 [INFO ] [rulesupport.loader.ScriptFileWatcher] - Loading script '/etc/openhab/automation/js/test.js'
2021-12-29 14:29:09.251 [INFO ] [org.openhab.automation.script.rules ] - Adding rule: Danfoss boost new
2021-12-29 14:29:14.840 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Test' received command ON
2021-12-29 14:29:17.319 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Test' changed from OFF to ON
2021-12-29 14:29:33.986 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Test' received command ON
2021-12-29 14:29:34.110 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Test' changed from OFF to ON
2021-12-29 14:29:56.353 [INFO ] [rulesupport.loader.ScriptFileWatcher] - Loading script '/etc/openhab/automation/js/test.js'
2021-12-29 14:30:10.029 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:30:26.992 [INFO ] [org.openhab.automation.script.rules ] - Adding rule: Danfoss boost new
2021-12-29 14:30:40.732 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Test' received command ON
2021-12-29 14:30:48.887 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:30:59.423 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:31:12.796 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Test' changed from OFF to ON
2021-12-29 14:31:23.870 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:31:31.673 [INFO ] [org.openhab.automation.script ] - Boost er aktiveret. Luftfugtighed: ${danfossRecentHumidity} %
2021-12-29 14:31:48.312 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while reading, caused by su.litvak.chromecast.api.v2.ChromeCastException: Remote socket closed
2021-12-29 14:31:48.322 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - <-- null payload in message
2021-12-29 14:31:51.079 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while sending 'PING', caused by java.net.SocketException: Broken pipe (Write failed)
2021-12-29 14:31:45.748 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf(Arrays.java:3745) ~[?:?]
at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:172) ~[?:?]
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:538) ~[?:?]
at java.lang.StringBuffer.append(StringBuffer.java:312) ~[?:?]
at java.io.StringWriter.write(StringWriter.java:106) ~[?:?]
at com.google.gson.stream.JsonWriter.string(JsonWriter.java:586) ~[?:?]
at com.google.gson.stream.JsonWriter.value(JsonWriter.java:418) ~[?:?]
at com.google.gson.internal.bind.TypeAdapters$16.write(TypeAdapters.java:406) ~[?:?]
at com.google.gson.internal.bind.TypeAdapters$16.write(TypeAdapters.java:390) ~[?:?]
at com.google.gson.internal.bind.TypeAdapterRuntimeTypeWrapper.write(TypeAdapterRuntimeTypeWrapper.java:69) ~[?:?]
at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$1.write(ReflectiveTypeAdapterFactory.java:127) ~[?:?]
at com.google.gson.internal.bind.ReflectiveTypeAdapterFactory$Adapter.write(ReflectiveTypeAdapterFactory.java:245) ~[?:?]
at com.google.gson.Gson.toJson(Gson.java:704) ~[?:?]
at com.google.gson.Gson.toJson(Gson.java:683) ~[?:?]
at com.google.gson.Gson.toJson(Gson.java:638) ~[?:?]
at com.google.gson.Gson.toJson(Gson.java:618) ~[?:?]
at org.openhab.core.events.AbstractEventFactory.serializePayload(AbstractEventFactory.java:88) ~[?:?]
at org.openhab.core.items.events.ItemEventFactory.createStateEvent(ItemEventFactory.java:255) ~[?:?]
at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.sendUpdate(ProfileCallbackImpl.java:125) ~[?:?]
at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onStateUpdateFromHandler(SystemDefaultProfile.java:53) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager.lambda$11(CommunicationManager.java:534) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager$$Lambda$1095/0x5dfec628.accept(Unknown Source) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager.lambda$13(CommunicationManager.java:554) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager$$Lambda$1096/0x5df74e28.accept(Unknown Source) ~[?:?]
at java.lang.Iterable.forEach(Iterable.java:75) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager.handleCallFromHandler(CommunicationManager.java:550) ~[?:?]
at org.openhab.core.thing.internal.CommunicationManager.stateUpdated(CommunicationManager.java:532) ~[?:?]
at org.openhab.core.thing.internal.ThingManagerImpl$1.stateUpdated(ThingManagerImpl.java:176) ~[?:?]
at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:231) ~[?:?]
at org.openhab.binding.synologysurveillancestation.handler.SynoCameraHandler.updateState(SynoCameraHandler.java:365) ~[?:?]
at org.openhab.binding.synologysurveillancestation.internal.thread.SynoApiThreadSnapshot.refresh(SynoApiThreadSnapshot.java:56) ~[?:?]
at org.openhab.binding.synologysurveillancestation.internal.thread.SynoApiThread.runOnce(SynoApiThread.java:135) ~[?:?]
2021-12-29 14:32:07.072 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:32:14.899 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:32:25.799 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@bbd51' takes more than 5000ms.
2021-12-29 14:32:49.133 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while handling, caused by java.net.SocketException: Broken pipe (Write failed)
2021-12-29 14:32:49.136 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while reading, caused by su.litvak.chromecast.api.v2.ChromeCastException: Remote socket closed
2021-12-29 14:32:49.138 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - <-- null payload in message
Of course JavaScript engine may not be to blame, but for sure on my system triggering some memory issues I don’t normally see.
What would be next steps for analyzing this further? How can I check how much memory is used by different add-ons?
Best regards,
Jacob Laursen