mhilbush
February 14, 2021, 11:33pm
121
@morph166955 I installed that jar, but OH wouldn’t finish loading the rules at startup. I confirmed the jar was installed and active. I tried to restart a couple times with the same result.
Ok. Ill try to rebuild and repost.
mhilbush
February 14, 2021, 11:51pm
123
Ok. When you repost, can you include the output from the console so that I can confirm the version number?
Will do. Not sure what’s getting stuck on yours, it loads on my test VM however that only has the one test rule in it. Ill pull a clean branch from git and just change the two relevant lines to make sure it’s perfectly compiled.
mhilbush
February 15, 2021, 12:11am
125
Ok, I have about 10 or so rules files that load, along with several dozen things and a few thousand items.
Spoiler alert, it didn’t help…
Going to try a few other things.
2021-02-15 02:22:34.305 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.306 [WARN ] [e.jetty.util.thread.QueuedThreadPool] -
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.308 [ERROR] [org.apache.felix.fileinstall ] - In main loop, we have serious trouble
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:26:05.103 [WARN ] [e.jetty.util.thread.QueuedThreadPool] -
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:26:05.103 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
@mhilbush New version updated. This reverts both [automation] Cache parsed script in order to improve performance by kaikreuzer · Pull Request #2057 · openhab/openhab-core · GitHub and [automation] Correctly return the evaluation result of DSL scripts by kaikreuzer · Pull Request #1952 · openhab/openhab-core · GitHub
I’m still not 100% sure that either of these are the cause, but I can’t find any other changes to the rules engine that would be causing this so I’m crossing my fingers. Worst case, we know what isn’t the problem.
openhab> bundle:update 177 file:///home/openhab/org.openhab.core.model.script.runtime-3.1.0-SNAPSHOT-threadpool23.jar
org.openhab.core.model.script.runtime-3.1.0-SNAPSHOT-threadpool23.jar
EDIT: Ignore RRD4J, it’s not the problem either…
EDIT 2: Opened [automation] memory leak caused by bad rule in UI · Issue #2200 · openhab/openhab-core · GitHub to track all of this.
mhilbush
February 15, 2021, 12:53pm
128
@morph166955 After installing your bundle, the problem still occurs.
Installing your bundle freed up the memory that was being held somewhere. But enabling the bad rule, still resulted in the continuous memory increase.
That’s very interesting. Also gives me some direction as it looks like the restarting of org.openhab.core.model.script.runtime caused the memory to free up which I would hope means that the leak is somewhere in there (or something associated with it). Thank you!
EDIT: For anyone who is following all of this, if you get to a point where you see the memory increasing but the system has not had an OOM crash, what happens when you do bundle:restart on org.openhab.core.model.script.runtime inside the karaf console? Does the memory release?
mhilbush
February 15, 2021, 3:37pm
130
Seaside
February 16, 2021, 8:16pm
131
Good work by @mhilbush and @morph166955 trying to fix this issue. I would like to see a comment by any of the maintainers for this problem, seems to be a big issue for a lot of people.
Regards, S
mhilbush
February 16, 2021, 9:00pm
132
You can see the latest status on the issue here.
opened 03:40AM - 15 Feb 21 UTC
closed 06:53PM - 20 Feb 21 UTC
Tested against S2207 but reported on https://community.openhab.org/t/openhab-3-r… uns-out-of-memory-java-heap-space-errors-cpu-100-after-a-few-hours/110924/105 as happening between 3.0 and 3.0.1
As identified by @mhilbush a rule similar to the rule below, but created on the new rules UI. This is 100% reproducible. I created an Ubuntu 20.04 VM (on ESXi) with 4GB ram. I only installed the systeminfo binding to monitor system use over time. I removed the rrd4j persistence as it was thought to be causing the problem at once point (it wasn't). There is nothing on this system other than a single thing created as per the config below.
```
rule "Test One per Second"
when
Time cron "* * * * * ? *"
then
xxxxxxx
var Number n = 1
end
```
Causes the following:
```
2021-02-15 03:25:52.728 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'aeefe05726' is executed.
2021-02-15 03:25:53.673 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '1' of rule 'aeefe05726' is triggered.
2021-02-15 03:25:53.735 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'aeefe05726' failed: ___ xxxxxxx
var Number n = 1
The method or field xxxxxxx is undefined; line 1, column 4, length 7
javax.script.ScriptException: ___ xxxxxxx
var Number n = 1
The method or field xxxxxxx is undefined; line 1, column 4, length 7
at org.openhab.core.model.script.runtime.internal.engine.DSLScriptEngine.eval(DSLScriptEngine.java:127) ~[?:?]
at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.lambda$0(ScriptActionHandler.java:62) [bundleFile:?]
at java.util.Optional.ifPresent(Optional.java:183) [?:?]
at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.execute(ScriptActionHandler.java:59) [bundleFile:?]
at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1179) [bundleFile:?]
at org.openhab.core.automation.internal.RuleEngineImpl.runRule(RuleEngineImpl.java:987) [bundleFile:?]
at org.openhab.core.automation.internal.TriggerHandlerCallbackImpl$TriggerData.run(TriggerHandlerCallbackImpl.java:89) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:834) [?:?]
```
Over time, this failure seems to cause a memory leak leading to an eventual system crash due to OutOfMemory
```
2021-02-15 02:22:34.305 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.307 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.306 [WARN ] [e.jetty.util.thread.QueuedThreadPool] -
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:22:34.308 [ERROR] [org.apache.felix.fileinstall ] - In main loop, we have serious trouble
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:26:05.103 [WARN ] [e.jetty.util.thread.QueuedThreadPool] -
java.lang.OutOfMemoryError: Java heap space
2021-02-15 02:26:05.103 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: Java heap space
```
systeminfo thing and items created as
```
openhab@oh3-test-vm:~$ cat /etc/openhab/things/systeminfo.things
Thing systeminfo:computer:test [interval_high=1, interval_medium=1]
openhab@oh3-test-vm:~$ cat /etc/openhab/items/systeminfo.items
String CPU_Name "Name" <none> { channel="systeminfo:computer:test:cpu#name" }
String CPU_Description "Description" <none> { channel="systeminfo:computer:test:cpu#description" }
Number CPU_Load1 "Load (1 min)" <none> { channel="systeminfo:computer:test:cpu#load1" }
Number CPU_Load5 "Load (5 min)" <none> { channel="systeminfo:computer:test:cpu#load5" }
Number CPU_Load15 "Load (15 min)" <none> { channel="systeminfo:computer:test:cpu#load15" }
Number CPU_Threads "Threads" <none> { channel="systeminfo:computer:test:cpu#threads" }
Number CPU_Uptime "Uptime" <time> { channel="systeminfo:computer:test:cpu#uptime" }
Number Memory_Available "Available" <none> { channel="systeminfo:computer:test:memory#available" }
Number Memory_Used "Used" <none> { channel="systeminfo:computer:test:memory#used" }
Number Memory_Total "Total" <none> { channel="systeminfo:computer:test:memory#total" }
Number Memory_Available_Percent "Available (%)" <none> { channel="systeminfo:computer:test:memory#availablePercent" }
Number Memory_Used_Percent "Used (%)" <none> { channel="systeminfo:computer:test:memory#usedPercent" }
```
I attempted to fix this in https://github.com/openhab/openhab-core/pull/2182 thinking that this was because of the threadpools but that was not successful. I also attempted to back out https://github.com/openhab/openhab-core/pull/2057 and https://github.com/openhab/openhab-core/pull/1952 to see if either of those were the problem. This was also fruitless. I am at a loss on where to move further and can not identify where the leak is.
mhilbush
February 20, 2021, 5:36pm
133
I submitted a fix for the invalid UI DSL rule memory leak. I’m aware of one other memory leak, but it occurs much less frequently, so should not be as critical. I’ll open a separate bug report for that issue shortly.
main ← mhilbush:ui-dsl-mem-fix2
opened 05:17PM - 20 Feb 21 UTC
Fixes #2200
Signed-off-by: Mark Hilbush <mark@hilbush.com>
Looks like there’s work ongoing for most of these problems. Is there any more info needed?
My memory usage for the last week looks like this:
(I started measuring this monday and short thereafter restarted OH)
Looks like it was committed and @Kai has cherry picked it for the next 3.0.x release.
Sascha_
February 21, 2021, 11:54am
136
I’ve deployed the Snapshot S2217 into my production today 10:33am and memory still looks good to me, only a slightly increasing graph:
Thank you all very much for this
mhilbush
February 21, 2021, 1:31pm
137
I opened a separate issue for another memory leak. This one is much less severe than the one caused by an invalid rule. I’m not clear yet on how this one should be fixed.
opened 01:03PM - 21 Feb 21 UTC
closed 06:29PM - 27 Feb 22 UTC
automation
There's a memory leak whenever a valid UI DSL rule is saved or enabled.
When … an existing UI DSL rule is saved or enabled, a new [DSLScriptEngine](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.model.script.runtime/src/org/openhab/core/model/script/runtime/internal/engine/DSLScriptEngine.java) is instantiated, which results in a call to [newScriptFromString](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.model.script.runtime/src/org/openhab/core/model/script/runtime/internal/engine/DSLScriptEngine.java#L126) in order to parse the script string.
However, the `resource` that was previously created for the rule [here](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.model.script.runtime/src/org/openhab/core/model/script/runtime/internal/engine/ScriptEngineImpl.java#L128) is still contained in the [resourceSet](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.model.script.runtime/src/org/openhab/core/model/script/runtime/internal/engine/ScriptEngineImpl.java#L60), but the reference to that resource is lost. Over time, as rules are edited and or disabled/enabled, resources will accumulate in the `resourceSet`.
The size of each resource is approximately 12 MB.
For anyone looking to test this, 3.1.0-S2216 and beyond should include the fix committed yesterday. I’d be very curious to know if someone wants to upgrade to the snapshot and see if it fixes the issues.
Schnuecks
February 22, 2021, 7:45am
139
I had setup my PI4 with the latest snapshot and it seems to solve that issue. Had run it over a few hours with that rules that break the other one and it runs at normal memory usage no error so far. thanks for all.
Is the latest snapshot stable enough to use it for my productive system? Actually I am using 3.1m1 without problems, separate from the heap space issue. Do you have any problems with the snapshot build?
