[Homematic] java.lang.OutOfMemoryError: unable to create new native thread

mastix commented 6 years ago

Hi guys,

My setup

OpenHAB 2.2 latest snapshot
OpenJDK Runtime Environment (Zulu 8.25.0.1-linux64) (build 1.8.0_152-b16)
Ubuntu 17.10 (x64) minimal - 768 MB RAM (only OpenHAB (incl. deps) installed)
- no special JRE heap settings (default values)

Expected Behavior

OpenHab rule updates values from CCU2 on a regular basis (via cron job).
When current power is >70mA it will set a switch to ON
When current power is below 70mA it will start a timer to check again in 7 minutes.
if it's still below below 70mA it will set switch to OFF and will send out a message

Expected: Everything should run stable. :)

See rule:

import org.openhab.model.script.actions.Timer
var Timer timer = null

rule "Washing Machine Turned ON/OFF"
when
    Item Leistungsmesser_WM_Current changed
then
    logInfo("Leistungsmesser_WM", "Power changed!")
    val actualPower = (Leistungsmesser_WM_Current.state as DecimalType);
    logInfo("Leistungsmesser_WM", "Actual Power is " + actualPower)
    if (actualPower > 70.00){
        logInfo("Leistungsmesser_WM", "Washingmachine = ON!")
        sendCommand(Wachingmaschine_Running,ON)
        if(timer!==null) {
            logInfo("Leistungsmesser_WM", "Turns out WM is not ready yet! Cancelled timer!.")
            timer.cancel
            timer = null
        }
    } else {
        logInfo("Leistungsmesser_WM", "Power Value dropped below threshold!")
        // don't switch it off yet... wait for about 7 minutes to check if it's really ready
        if (timer === null) {
            logInfo("Leistungsmesser_WM", "Will start 7-minute-timer to check if it's really done.")
            timer = createTimer(now.plusMinutes(7)) [|
                logInfo("Leistungsmesser_WM", "Value did not change for 7 minutes - switching it off!")
                logInfo("Leistungsmesser_WM", "Washingmachine = OFF!")
                sendCommand(Wachingmaschine_Running,OFF)
                timer = null
            ]
        }
    }
end

Questions upfront

Is there some manual heap tweaking necessary when using 768MB RAM? Is there a memory leak in my rule? Is it ok, to poll the values from CCU2 every x minutes or is there a better way?

Current Behavior

I'm getting an OOM error every once in a while - of course it's not easily reproducible:

2017-11-16 13:42:00.347 [INFO ] [home.model.script.Leistungsmesser_WM] - Actual Power is 111.00 2017-11-16 13:42:00.348 [INFO ] [home.model.script.Leistungsmesser_WM] - Washingmachine = ON! 2017-11-16 13:45:00.291 [INFO ] [home.model.script.Leistungsmesser_WM] - Power changed! 2017-11-16 13:45:00.295 [INFO ] [home.model.script.Leistungsmesser_WM] - Actual Power is 110.00 2017-11-16 13:45:00.298 [INFO ] [home.model.script.Leistungsmesser_WM] - Washingmachine = ON! 2017-11-16 13:47:42.548 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - qtp57733118{FAILED,8<=5<=200,i=4,q=0} rejected org.eclipse.jetty.io.ManagedSelector@2879f9f4 id=0 keys=0 selected=0 2017-11-16 13:48:00.003 [ERROR] [ore.internal.events.OSGiEventManager] - Dispatching/filtering event for subscriber 'org.eclipse.smarthome.core.events.EventSubscriber' failed: java.lang.OutOfMemoryError: unable to create new native thread java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: unable to create new native thread at java.util.concurrent.FutureTask.report(FutureTask.java:122) [?:?] at java.util.concurrent.FutureTask.get(FutureTask.java:206) [?:?] at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.eclipse.smarthome.core.internal.events.OSGiEventManager.dispatchESHEvent(OSGiEventManager.java:203) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.eclipse.smarthome.core.internal.events.OSGiEventManager.handleEvent(OSGiEventManager.java:176) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.eclipse.smarthome.core.internal.events.OSGiEventManager.handleEvent(OSGiEventManager.java:158) [97:org.eclipse.smarthome.core:0.9.0.201711151730] at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415) [3:org.apache.karaf.services.eventadmin:4.1.2] at org.apache.felix.eventadmin.impl.tasks.HandlerTask.run(HandlerTask.java:90) [3:org.apache.karaf.services.eventadmin:4.1.2] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) ~[?:?] at java.lang.Thread.start(Thread.java:717) ~[?:?] at java.util.Timer.(Timer.java:160) ~[?:?] at java.util.Timer.(Timer.java:132) ~[?:?] at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:45) ~[?:?] at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.disableDatapoint(AbstractHomematicGateway.java:730) ~[?:?] at org.openhab.binding.homematic.internal.communicator.virtual.ReloadAllFromGatewayVirtualDatapointHandler.handleCommand(ReloadAllFromGatewayVirtualDatapointHandler.java:55) ~[?:?] at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway$1.execute(AbstractHomematicGateway.java:552) ~[?:?] at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:61) ~[?:?] at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:544) ~[?:?] at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:523) ~[?:?] at org.openhab.binding.homematic.handler.HomematicThingHandler.handleCommand(HomematicThingHandler.java:175) ~[?:?] at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl$1.call(ProfileCallbackImpl.java:61) ~[?:?] at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl$1.call(ProfileCallbackImpl.java:1) ~[?:?] at org.eclipse.smarthome.core.common.SafeMethodCaller.executeDirectly(SafeMethodCaller.java:218) ~[?:?] at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:189) ~[?:?] at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83) ~[?:?] at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67) ~[?:?] at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:58) ~[?:?]

Does anyone have any idea? Any help would be appreciated! 👍

Regards,

Sascha

mjagdis commented 6 years ago

Run "systemctl show openhab2.service" and look for a TasksMax setting. If it is anything other than "infinity" try "systemctl --runtime set-property openhab2.service TasksMax=infinity". If that's the problem you either need to add the TasksMax setting to the openhab2.service file or run the set-property thing again without the --runtime so it will persist across reboots.

A while back the systemd folks decided that people should be protected for their own good and decided to make TasksMax default to 512 (I think). That leads to exactly this fork failure in thread-hungry java. Took out my Minecraft server just yesterday so it's all in my scroll back :-)

mastix commented 6 years ago

Hey @mjagdis ,

thanks for the hint!

I'll give it a shot and will update this issue as soon as I can confirm this settings fixed things!

Greetz,

Sascha

mastix commented 6 years ago

Problem still occurs: :(

Value is set:

TasksMax=18446744073709551615

2017-11-18 17:42:00.032 [ERROR] [ore.internal.events.OSGiEventManager] - Dispatching/filtering event for subscriber 'org.eclipse.smarthome.core.events.EventSubscriber' failed: java.lang.OutOfMemoryError: unable to create new native thread
java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: unable to create new native thread
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) [?:?]
        at java.util.concurrent.FutureTask.get(FutureTask.java:206) [?:?]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.eclipse.smarthome.core.internal.events.OSGiEventManager.dispatchESHEvent(OSGiEventManager.java:203) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.eclipse.smarthome.core.internal.events.OSGiEventManager.handleEvent(OSGiEventManager.java:176) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.eclipse.smarthome.core.internal.events.OSGiEventManager.handleEvent(OSGiEventManager.java:158) [97:org.eclipse.smarthome.core:0.9.0.201711151730]
        at org.apache.felix.eventadmin.impl.handler.EventHandlerProxy.sendEvent(EventHandlerProxy.java:415) [3:org.apache.karaf.services.eventadmin:4.1.2]
        at org.apache.felix.eventadmin.impl.tasks.HandlerTask.run(HandlerTask.java:90) [3:org.apache.karaf.services.eventadmin:4.1.2]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.OutOfMemoryError: unable to create new native thread
        at java.lang.Thread.start0(Native Method) ~[?:?]
        at java.lang.Thread.start(Thread.java:717) ~[?:?]
        at java.util.Timer.<init>(Timer.java:160) ~[?:?]
        at java.util.Timer.<init>(Timer.java:132) ~[?:?]
        at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:45) ~[?:?]
        at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.disableDatapoint(AbstractHomematicGateway.java:730) ~[?:?]
        at org.openhab.binding.homematic.internal.communicator.virtual.ReloadAllFromGatewayVirtualDatapointHandler.handleCommand(ReloadAllFromGatewayVirtualDatapointHandler.java:55) ~[?:?]
        at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway$1.execute(AbstractHomematicGateway.java:552) ~[?:?]
        at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:61) ~[?:?]
        at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:544) ~[?:?]
        at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:523) ~[?:?]
        at org.openhab.binding.homematic.handler.HomematicThingHandler.handleCommand(HomematicThingHandler.java:175) ~[?:?]
        at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl$1.call(ProfileCallbackImpl.java:61) ~[?:?]
        at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl$1.call(ProfileCallbackImpl.java:1) ~[?:?]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.executeDirectly(SafeMethodCaller.java:218) ~[?:?]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:189) ~[?:?]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83) ~[?:?]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67) ~[?:?]

Any more ideas? Is my rule OK? It looks like it's happing around 18-20 minutes after the washing machine has stopped.

lampi87 commented 6 years ago

Same for me. I get the OutOfMemory exception when ccu is not available anymore All of my rules are "Item... Changed" so no polling within my rules

Flole998 commented 6 years ago

Same here after I configured a bridge which is not here yet.

mdicke2s commented 6 years ago

@mastix As @FStolte mentioned, this bug may be related to #3388. Could you please verify if the issue is still valid with OpenHab 2.3.0?

mdicke2s commented 6 years ago

This issue was moved to eclipse/smarthome#5787

bunglex commented 3 years ago

mjagdis - i have had openhab2 working well on ubuntu with a zwave stick until a recent upgrade (i upgrade frequently). Changing TasksMax=infinity seems to have sorted my problem - not sure why it presented itself in 2020, but many thanks.

openhab / openhab-addons