OH4 runs out of memory

Platform information:

  • Hardware: Raspberry Pi 4 / 4GB ram / 64GB SD
  • OS: latest openHABian
  • Java Runtime Environment: openJDK 17 - latest, as installed by openHABian
  • openHAB version: 4.0.1 - latest, as installed by openHABian

As part of the migration I created a complete fresh setup with OH 4.0.1
Everything seemed to work fine, but then I run out of memory after 20-30min, sometimes up to 2h
I removed most of the bindings and rules, but problem is the same
I increased heap size, but still the same

EXTRA_JAVA_OPTS="-Xms256m -Xmx768m -XX:+ExitOnOutOfMemoryError"

shell:info shows

 Current heap size           165,872 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         267,500 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
Error executing command: unable to create native thread: possibly out of memory or process/resource limits reached

I ran shell:info shows multiple times before and it looked good (in fact heap size was reduced since startup). And 10min later I get this error.

I had 2 UI instances running for a while working on things and items.

Are there any know issues with regards to general memory leaks with the 4.0.1 release?

Logfile shows ** Stopped without executing or closing null**

2023-08-14 21:01:21.837 [INFO ] [y.internal.handler.ShellyBaseHandler] - shelly1pm-8caab505fcf4: INFO: Neue Firmware verfügbar: aktuelle Version: 20221108-153925/v1.12.1-1PM-fix-g2821131, neue Version: 20230503-101420/v1.13.0-g9aed950
2023-08-14 21:01:26.201 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:01:27.277 [INFO ] [g.sony.internal.AbstractThingHandler] - Starting state polling every 30 seconds
2023-08-14 21:10:02.953 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:15:21.621 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:24:47.749 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: Invalid URI host: null (authority: 192.1686.7:8080)
	at org.eclipse.jetty.client.HttpClient.checkHost(HttpClient.java:541) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.newHttpRequest(HttpClient.java:526) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.newRequest(HttpClient.java:484) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.newRequest(HttpClient.java:473) ~[?:?]
	at org.openhab.binding.remoteopenhab.internal.rest.RemoteopenhabRestClient.executeUrl(RemoteopenhabRestClient.java:565) ~[?:?]
	at org.openhab.binding.remoteopenhab.internal.rest.RemoteopenhabRestClient.executeGetUrl(RemoteopenhabRestClient.java:559) ~[?:?]
	at org.openhab.binding.remoteopenhab.internal.rest.RemoteopenhabRestClient.tryApi(RemoteopenhabRestClient.java:162) ~[?:?]
	at org.openhab.binding.remoteopenhab.internal.handler.RemoteopenhabBridgeHandler.checkConnection(RemoteopenhabBridgeHandler.java:376) ~[?:?]
	at org.openhab.binding.remoteopenhab.internal.handler.RemoteopenhabBridgeHandler.lambda$0(RemoteopenhabBridgeHandler.java:182) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
2023-08-14 21:26:02.867 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:26:39.441 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'remoteopenhab:server:192_168_6_7' to inbox.
2023-08-14 21:40:03.113 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:44:41.511 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:52:16.765 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 21:59:03.106 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:01:09.651 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'shelly:shellybulbduo:d0cb5a' to inbox.
2023-08-14 22:04:20.374 [INFO ] [org.openhab.core.model.script.keyfob] - Keyfob event: 255.0
2023-08-14 22:04:44.268 [INFO ] [y.internal.handler.ShellyBaseHandler] - shellygas-50029178b4ac: INFO: Neue Firmware verfügbar: aktuelle Version: 20221027-111245/v1.12.1-ga9117d3, neue Version: 20230503-102300/v1.13.0-g9aed950
2023-08-14 22:14:37.740 [INFO ] [nhab.core.model.script.Shutter_Erker] - Open shutters Erker
2023-08-14 22:14:37.749 [INFO ] [nhab.core.model.script.Shutter_Erker] - Open shutters Erker
2023-08-14 22:17:01.466 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:21:02.975 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:24:41.605 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:25:01.510 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:28:21.536 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null
2023-08-14 22:43:52.708 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@14b3f35' takes more than 5000ms.
2023-08-14 22:44:21.364 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - 
java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached
	at java.lang.Thread.start0(Native Method) ~[?:?]
	at java.lang.Thread.start(Thread.java:802) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:945) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1593) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:346) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562) ~[?:?]
	at org.eclipse.jetty.util.thread.ScheduledExecutorScheduler.schedule(ScheduledExecutorScheduler.java:125) ~[bundleFile:9.4.50.v20221201]
	at org.eclipse.jetty.util.SocketAddressResolver$Async.lambda$resolve$1(SocketAddressResolver.java:157) ~[bundleFile:9.4.50.v20221201]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[bundleFile:9.4.50.v20221201]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[bundleFile:9.4.50.v20221201]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]

I’m wondering, because the Sony binding is not marked as installed under Settings->Bindings, but shows up in the log. I installed it before, removed it to narrow potential candidates, but still shows up in the log.
bundle:list indicates the binding as installed, but not active

236 │ Active    │  80 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Automation :: JavaScript Scripting
237 │ Active    │  80 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Amazon Dash Button Binding
238 │ Active    │  80 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Astro Binding
244 │ Active    │  80 │ 4.0.1                  │ openHAB UI :: Bundles :: HABPanel UI
245 │ Active    │  80 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Automation :: JavaScript Scripting (Nashorn)
248 │ Active    │  75 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Transformation Service :: Map
254 │ Active    │  75 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Transformation Service :: XPath
255 │ Active    │  80 │ 0.3.0.v20220506-1020   │ EdDSA-Java
256 │ Active    │  80 │ 2.7.4                  │ Californium (Cf) Core
257 │ Active    │  80 │ 2.7.4                  │ Californium (Cf) Element Connector
258 │ Active    │  80 │ 2.7.4                  │ Californium (Cf) OSGi
259 │ Active    │  80 │ 2.7.4                  │ Scandium (Sc) Core
275 │ Active    │  80 │ 4.1.0.202308122207     │ openHAB Add-ons :: Bundles :: Shelly Binding Gen1+2
281 │ Installed │  80 │ 4.0.0.202305291652     │ openHAB Add-ons :: Bundles :: Sony Binding
282 │ Active    │  80 │ 4.0.1                  │ openHAB Add-ons :: Bundles :: Remote openHAB Binding

The addons folder is empty, but there is openhab-addons-4.0.1.kar - is that correct?

I noticed when I do a “feature:install openhab-transport-coap” that OH crashes/restarts. Even the console is ended. After starting the console again, I’m able to activate the Shelly binding. This happens each time when I clean the cache and need to re-install the coap transport.

See what happens when I run shell:info command every 3sec:
heap grows rapidly to about 220MB and then drops to 170, grows again…

openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           169,590 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           186,391 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           192,006 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           194,293 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           197,851 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           199,981 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           203,248 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           204,398 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           208,816 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                         Current heap size           173,544 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           177,355 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes
openhab> shell:info | grep heap                                                                                                                                                       
  Current heap size           182,034 kbytes
  Maximum heap size           760,320 kbytes
  Committed heap size         253,952 kbytes

When I shutdown OH I see

2023-08-14 23:26:27.757 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2023-08-14 23:26:28.246 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler ShellyRelayHandler tried updating the thing status although the handler was already disposed.
2023-08-14 23:26:40.171 [WARN ] [service.spi.util.WebContainerManager] - Can't get a WebContainer service from {org.osgi.service.http.HttpService, org.ops4j.pax.web.service.WebContainer}={org.ops4j.pax.web.log.ncsa.extended=true, org.ops4j.pax.web.ssl.keystore.password=********, service.scope=bundle, org.ops4j.pax.web.ssl.key.password=********, org.ops4j.pax.web.session.cookie.name=JSESSIONID, org.osgi.service.http.connector.name=default, org.ops4j.pax.web.enc.iterationcount=1000, org.ops4j.pax.web.log.ncsa.file=yyyy_mm_dd.request.log, org.ops4j.pax.web.server.eventDispatcherThreadCount=1, org.osgi.service.http.checkForwardedHeaders=false, org.ops4j.pax.web.enc.suffix=), org.ops4j.pax.web.digestAuth.maxNonceAge=60000, org.ops4j.pax.web.ssl.ciphersuites.included=, org.ops4j.pax.web.session.url=jsessionid, org.ops4j.pax.web.formAuth.errorRedirect=false, org.ops4j.pax.web.ssl.ciphersuites.excluded=^.*_(MD5|SHA|SHA1)$,^TLS_RSA_.*$,^SSL_.*$,^.*_NULL_.*$,^.*_anon_.*, org.ops4j.pax.web.enc.prefix=ENC(, org.ops4j.pax.web.server.maxThreads=50, org.ops4j.pax.web.validatePeerCerts=false, service.id=125, org.ops4j.pax.web.session.cookie.maxAge=-1, org.ops4j.pax.web.ssl.truststore.password=********, org.ops4j.pax.web.ssl.session.cacheSize=-1, org.ops4j.pax.web.ssl.truststore.type=JKS, org.ops4j.pax.web.ssl.keystore.type=JKS, org.ops4j.pax.web.ssl.session.enabled=true, org.ops4j.pax.web.ssl.protocol=TLSv1.3, org.osgi.service.http.port=8080, org.ops4j.pax.web.log.ncsa.file.date.format=yyyy-MM-dd, org.ops4j.pax.web.ssl.renegotiationLimit=-1, org.osgi.service.http.secure.enabled=true, org.osgi.service.http.enabled=true, org.ops4j.pax.web.server.idleTimeout=300000, org.ops4j.pax.web.log.ncsa.retaindays=90, org.ops4j.pax.web.log.ncsa.logtimezone=GMT, org.ops4j.pax.web.enc.algorithm=PBEWithHmacSHA256AndAES_128, org.ops4j.pax.web.validateCerts=false, org.ops4j.pax.web.config.files=/usr/share/openhab/runtime/etc/jetty.xml, org.ops4j.pax.web.ssl.renegotiationAllowed=true, org.ops4j.pax.web.digestAuth.maxNonceCount=1024, org.ops4j.pax.web.enableOCSP=false, org.ops4j.pax.web.ssl.clientauth.needed=false, org.ops4j.pax.web.enc.enabled=false, org.osgi.service.http.port.secure=8443, javax.servlet.context.tempdir=/var/lib/openhab/tmp, org.ops4j.pax.web.enableCRLDP=false, org.ops4j.pax.web.server.connector.idleTimeout=30000, org.ops4j.pax.web.session.timeout=10, org.ops4j.pax.web.ssl.clientauth.wanted=false, org.ops4j.pax.web.ssl.protocols.excluded=SSL,SSLv2,SSLv2Hello,SSLv3, service.bundleid=222, org.ops4j.pax.web.server.minThreads=2, org.ops4j.pax.web.session.cookie.secure=false, org.ops4j.pax.web.enc.masterpassword=********, org.ops4j.pax.web.log.ncsa.append=true, org.osgi.service.http.secure.connector.name=secureDefault, org.ops4j.pax.web.ssl.session.timeout=-1, org.ops4j.pax.web.listening.addresses=0.0.0.0, org.ops4j.pax.web.log.ncsa.buffered=true, org.ops4j.pax.web.session.cookie.sameSite=unset, org.ops4j.pax.web.log.ncsa.enabled=false, org.ops4j.pax.web.ssl.protocols.included=, org.ops4j.pax.web.session.cookie.httpOnly=true, org.ops4j.pax.web.server.showStacks=false}

That’s actually not an increase if on a 4GB box. Try omitting or even 2g. Increase Xms, too, eventually.

changed to 2048 and removed another rules file, let’s see

What do you think about “2023-08-15 06:50:18.440 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - Stopped without executing or closing null” messages?
I found this:

192.1686.7 is not a valid ip address, dot missing.

Arne

1 Like

hmm, I See that in the log above, but find it in the whole json db
I uninstalled the remote openHAB binding, so far looks look
I’m cleaning up the remote system, maybe it is related to a ton of old entries (I use this Pi in between only as a Z-Wave hub, but there was still a lot configured).

I had it running, mostly it was remotes to the remote server addon with a lot of auto-discovered items. Then I stripped down the remote installation by 75%, recreated the thing (no importing the OH3 config) and everything worked fine. Now I re-added the missing bindings (which link to existing things) and problem is back.

Is there a way to find out, which addon is consuming what amount of memory/heap? Or do I need to go the „strip down and re-add bindings/things one by one“, which is a hazzle…

The best approach is to create a memory heap dump when it is almost full and then analyze it with a tool like:

The leak can be anywhere not just in the add-on. It could also be in OH Core or some third party library the add-on code uses.

1 Like