At the beginning of this week my system updated to 4.1.0.M1 (I should stay on stable).
Since then the problems have been increasing. I had so much stress after migrating from 3.x to 4.0. This is really frustrating.
Since the update, my system stops after about 4 hours with an out-of-memory error.
Tail throws so many LOGs that I can’t even see what was last “normal” in LOG.
How can I analyze this error. I suspect that a binding is the cause.
At the same time, I have the problem that I can no longer access OH via Alexa.
All OH devices show “a problem has occurred” in the Alexa APP. When I speak to ALEXA, I always have to rebind the skill.
I have already completely uninstalled the Alexa binding and used the alternative SmarthomeJ. Both don’t work.
But I’m not sure whether this triggers my out-of-memory error. Just a feeling.
My system runs on an RPI4
2023-09-21 06:47:15.675 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
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.reExecutePeriodic(ScheduledThreadPoolExecutor.java:360) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307) ~[?:?]
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) ~[?:?]
With OOM exceptions, the exception is a symptom, not a cause. About the only useful information you will find there is the fact that an OOM exception occurred.
To find the memory leak itself is either going to take a lot of highly technical skills to hook a profiler up to OH while it’s running and analyze the memory to see what appears to be leaking memory. Or a lot of trial and error by removing add-ons in a systematic way until the OOM goes away. Then you’ll know which binding is causing the problem.
I agree it is most likely a specific binding as this is the first OOM error I’ve seen reported for OH 4.1. If it were in core, someone most likely would have experienced it before now and reported it.
It is worth to say the binding did not change, and there was no growth in threads (memory usage) at all before. So something changed in core that caused this problem to appear now. It was bad design in the binding, but never caused a real problem so far. We have not been able to identify what change caused it. Maybe another binding is affected in a similar way.
Hello,
OK, then I’ll switch off the bindings one after the other.
Let’s start with the Alexa binding, that doesn’t work right now anyway.
Here is a list of my installed bindings.
After the Alexa binding I can then remove the 4.0.0 bindings.
28 x Active x 80 x 4.0.0.202303300929 x openHAB Add-ons :: Bundles :: iCloud Binding
267 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Automation :: JavaScript S
269 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Astro Binding
270 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Exec Binding
271 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Homematic Binding
272 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: HTTP Binding
273 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: hue Binding
274 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: iCalendar Binding
275 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Mail Binding
276 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT Broker Binding
277 x Active x 81 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT EspMilightHub
278 x Active x 81 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT Things and Channels
279 x Active x 82 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT HomeAssistant Convent
280 x Active x 82 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT Homie Convention
281 x Active x 82 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: MQTT Ruuvi Gateway
282 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: NTP Binding
283 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: OpenWeatherMap Binding
284 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Roku Binding
285 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Sonos Binding
286 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Systeminfo Binding
287 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Telegram Binding
288 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: TR-064 Binding
293 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: IO :: Homekit
294 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: IO :: openHAB Cloud Connec
295 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Persistence Service :: RRD
296 x Active x 75 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Transformation Service ::
297 x Active x 75 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Transformation Service ::
298 x Active x 75 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Transformation Service ::
299 x Active x 75 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Transformation Service ::
302 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Voice :: VoiceRSS Text-to-
304 x Active x 80 x 4.0.0.202305291652 x openHAB Add-ons :: Bundles :: Sony Binding
319 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: SamsungTV Binding
320 x Active x 80 x 4.1.0.M1 x openHAB Add-ons :: Bundles :: Amazon Echo Control Binding
Thanks for the feedback
PS: Now I’ve said so casually that I’d better switch back to stable. But is it even possible without reinstalling?
Try switching of the Sony binding first. It is from the same developer as the Neeo binding. He did a great job on these bindings, but might have used the same way of doing things in both bindings, leading to the same problem.
Last night at 4:00 a.m. I woke up and looked straight into the LOG.
OH had stopped again at 12:13 a.m.
I then uninstalled the HTTP binding. Since then OH seems to be working. However, I did not reboot after uninstalling.
I’ll wait a few more hours until I give the “all clear”.
2023-09-22 00:13:28.721 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
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 jdk.internal.net.http.HttpClientImpl.start(HttpClientImpl.java:337) ~[java.net.http:?]
at jdk.internal.net.http.HttpClientImpl.create(HttpClientImpl.java:271) ~[java.net.http:?]
at jdk.internal.net.http.HttpClientBuilderImpl.build(HttpClientBuilderImpl.java:135) ~[java.net.http:?]
at org.apache.cxf.transport.http.HttpClientHTTPConduit.setupConnection(HttpClientHTTPConduit.java:231) ~[?:?]
at org.apache.cxf.transport.http.HTTPConduit.prepare(HTTPConduit.java:529) ~[?:?]
at org.apache.cxf.interceptor.MessageSenderInterceptor.handleMessage(MessageSenderInterceptor.java:47) ~[?:?]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) ~[?:?]
at org.apache.cxf.jaxrs.client.AbstractClient.doRunInterceptorChain(AbstractClient.java:710) ~[?:?]
at org.apache.cxf.jaxrs.client.WebClient.doChainedInvocation(WebClient.java:1086) ~[?:?]
at org.apache.cxf.jaxrs.client.WebClient.doInvoke(WebClient.java:932) ~[?:?]
at org.apache.cxf.jaxrs.client.WebClient.doInvoke(WebClient.java:901) ~[?:?]
at org.apache.cxf.jaxrs.client.WebClient.invoke(WebClient.java:461) ~[?:?]
at org.apache.cxf.jaxrs.client.SyncInvokerImpl.method(SyncInvokerImpl.java:150) ~[?:?]
at org.apache.cxf.jaxrs.client.SyncInvokerImpl.method(SyncInvokerImpl.java:145) ~[?:?]
at org.apache.cxf.jaxrs.client.SyncInvokerImpl.post(SyncInvokerImpl.java:85) ~[?:?]
at org.apache.cxf.jaxrs.client.spec.InvocationBuilderImpl.post(InvocationBuilderImpl.java:153) ~[?:?]
at org.openhab.binding.sony.internal.net.HttpRequest.sendPostCommand(HttpRequest.java:158) ~[?:?]
at org.openhab.binding.sony.internal.net.HttpRequest.sendPostJsonCommand(HttpRequest.java:138) ~[?:?]
at org.openhab.binding.sony.internal.transports.SonyHttpTransport.executePostJson(SonyHttpTransport.java:331) ~[?:?]
at org.openhab.binding.sony.internal.transports.SonyHttpTransport.executePostJson(SonyHttpTransport.java:308) ~[?:?]
at org.openhab.binding.sony.internal.transports.SonyHttpTransport.execute(SonyHttpTransport.java:129) ~[?:?]
at org.openhab.binding.sony.internal.transports.SonyTransport.execute(SonyTransport.java:108) ~[?:?]
at org.openhab.binding.sony.internal.scalarweb.models.ScalarWebService.execute(ScalarWebService.java:311) ~[?:?]
at org.openhab.binding.sony.internal.scalarweb.models.ScalarWebService.executeSpecific(ScalarWebService.java:293) ~[?:?]
at org.openhab.binding.sony.internal.scalarweb.models.ScalarWebService.execute(ScalarWebService.java:272) ~[?:?]
at org.openhab.binding.sony.internal.scalarweb.ScalarWebHandler.connect(ScalarWebHandler.java:313) ~[?:?]
at org.openhab.binding.sony.internal.AbstractThingHandler.doConnect(AbstractThingHandler.java:136) ~[?:?]
at org.openhab.binding.sony.internal.AbstractThingHandler.lambda$1(AbstractThingHandler.java:343) ~[?:?]
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) ~[?:?]
In your log output, I see the Sony binding is using the same library for http requests as in the Neeo binding. We had an issue of threads not being closed there. You can monitor the number of threads from the console:
Do this at regular intervals and see if it the number keeps on growing.
Disable the Sony binding, restart, and look at the impact. Does it still grow.
My suspicion is with that binding, not the http binding. Unfortunately, it is not in the official repository, and I don’t have Sony equipment, so can’t solve the issue if it would be confirmed to be the problem.
Hello Mark,
I have executed the command about 7 times in the last 10 minutes.
The number is gradually increasing.
On the first try it was at 2094. Now it is at 2276.
However, I don’t understand why my system hasn’t stopped since I uninstalled the HTTP binding. By the way, I use the official OH HTTP binding.
Should I now remove the Sony binding, or should I wait until OH stops again?
Not only the HTTP binding uses http calls. Other bindings that may use http do not rely on the http binding for that. I would indeed try to uninstall the Sony binding.
The growth in threads is more than what is acceptable. So I am convinced the issue is there. We just need to confirm it is actually the Sony binding.
Hi!
When I upgraded from 3 to 4, I first had to resolve a java version issue. Once that was resolved, I faced similar issues with the OH system becoming nearly inaccessible after 3 to 4 hours after reboot.
I found that the file system filled up due to extensive logging. The system and daemon logs in /var/log grew fast. I first tried combatting this by modifying the rotatelogs settings, but realized I needed to find the root cause, when rotating logs needed to be done very frequently.
Eventually I found that others (Linux users in general) had encountered similar issues after having upgraded grafana. Once I downgraded grafana to the previous version, the overflowing logs behavior stopped and my Raspberry Pi is behaving normally again.
I hope this helps.
Hello,
I experience the same issue. Started with a new installation of OH4.0.3 copied all my items and rules, everything works well but after some hours system gets slow and does foinaly not work. Error is
java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached.
Uninstalled the http binding but issue remains
shell:threads | grep -i httpclient | grep -i runnable | wc -l
is about 7-9 without http binding.
my used bindings are :
237 │ Active │ 75 │ 4.0.3 │ org.openhab.transform.regex
238 │ Active │ 75 │ 4.0.3 │ org.openhab.transform.jsonpath
239 │ Active │ 80 │ 4.0.3 │ org.openhab.automation.jsscripting
240 │ Active │ 80 │ 4.0.3 │ org.openhab.persistence.rrd4j
241 │ Active │ 80 │ 4.0.3 │ org.openhab.persistence.mapdb
243 │ Active │ 80 │ 4.0.3 │ org.openhab.persistence.influxdb
244 │ Active │ 80 │ 4.0.3 │ org.openhab.ui.habpanel
245 │ Active │ 80 │ 4.0.3 │ org.openhab.ui.basic
246 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.astro
247 │ Active │ 80 │ 5.2.1.OH1 │ nrjavaserial
248 │ Active │ 80 │ 3.9.0 │ org.apache.commons.commons-net
249 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.enocean
250 │ Active │ 80 │ 4.0.3 │ org.openhab.core.config.discovery.usbserial
251 │ Active │ 80 │ 4.0.3 │ org.openhab.core.config.discovery.usbserial.linuxsysfs
252 │ Active │ 80 │ 4.0.3 │ org.openhab.core.config.discovery.usbserial.ser2net
253 │ Active │ 80 │ 4.0.3 │ org.openhab.core.config.serial
254 │ Active │ 80 │ 4.0.3 │ org.openhab.core.io.transport.serial
255 │ Active │ 80 │ 4.0.3 │ org.openhab.core.io.transport.serial.rxtx
256 │ Active │ 80 │ 4.0.3 │ org.openhab.core.io.transport.serial.rxtx.rfc2217
258 │ Active │ 80 │ 2.7.1.OH1 │ org.jupnp
259 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.hue
260 │ Active │ 80 │ 4.0.3 │ org.openhab.core.config.discovery.upnp
261 │ Active │ 80 │ 4.0.3 │ org.openhab.core.io.transport.upnp
262 │ Active │ 80 │ 0.3.0.v20220506-1020 │ net.i2p.crypto.eddsa
263 │ Active │ 80 │ 2.7.4 │ org.eclipse.californium.core
264 │ Active │ 80 │ 2.7.4 │ org.eclipse.californium.element-connector
265 │ Active │ 80 │ 2.7.4 │ org.eclipse.californium.osgi
266 │ Active │ 80 │ 2.7.4 │ org.eclipse.californium.scandium
267 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.shelly
268 │ Active │ 80 │ 1.6.2 │ com.sun.mail.javax.mail
269 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.mail
270 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.avmfritz
272 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.icalendar
273 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.mielecloud
274 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.network
275 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.openweathermap
276 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.sonos
277 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.telegram
278 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.weathercompany
279 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.ntp
280 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.homewizard
281 │ Active │ 80 │ 2.27 │ com.google.dagger
282 │ Active │ 80 │ 1.2.2 │ com.hivemq.client.mqtt
283 │ Active │ 80 │ 4.1.92.Final │ io.netty.buffer
284 │ Active │ 80 │ 4.1.92.Final │ io.netty.codec
285 │ Active │ 80 │ 4.1.92.Final │ io.netty.codec-http
286 │ Active │ 80 │ 4.1.92.Final │ io.netty.codec-socks
287 │ Active │ 80 │ 4.1.92.Final │ io.netty.common
288 │ Active │ 80 │ 4.1.92.Final │ io.netty.handler
289 │ Active │ 80 │ 4.1.92.Final │ io.netty.handler-proxy
290 │ Active │ 80 │ 4.1.92.Final │ io.netty.resolver
291 │ Active │ 80 │ 2.0.60.Final │ io.netty.tcnative-classes
292 │ Active │ 80 │ 4.1.92.Final │ io.netty.transport
293 │ Active │ 80 │ 4.1.92.Final │ io.netty.transport-classes-epoll
294 │ Active │ 80 │ 4.1.92.Final │ io.netty.transport-native-unix-common
295 │ Active │ 80 │ 2.2.19 │ io.reactivex.rxjava2.rxjava
296 │ Active │ 80 │ 2.1.2 │ org.jctools.core
297 │ Active │ 80 │ 4.0.3 │ org.openhab.binding.mqtt
298 │ Active │ 81 │ 4.0.3 │ org.openhab.binding.mqtt.espmilighthub
299 │ Active │ 81 │ 4.0.3 │ org.openhab.binding.mqtt.generic
300 │ Active │ 82 │ 4.0.3 │ org.openhab.binding.mqtt.homeassistant
301 │ Active │ 82 │ 4.0.3 │ org.openhab.binding.mqtt.homie
302 │ Active │ 82 │ 4.0.3 │ org.openhab.binding.mqtt.ruuvigateway
303 │ Active │ 80 │ 4.0.3 │ org.openhab.core.io.transport.mqtt
304 │ Active │ 80 │ 1.0.3 │ org.reactivestreams.reactive-streams
307 │ Active │ 80 │ 4.0.0.202309181149 │ org.openhab.binding.lgthinq
