[Solved] Task java.util.concurrent.ScheduledThreadPoolExecutor ScheduledFutureTask Not completed.. errors

vespaman · July 16, 2021, 9:07am

The last week, I have started seeing this error on different things. Has anyone a clue what is wrong with my setup? I’m on 3.1 and I can’t remember doing anything special with my box lately. Or maybe they have always been there since I upgraded to 3.1 last month, and I have just not seen them…
Example below shows one node on zwave, and weatherflow just following each other.

First I thought it had something to do with rules, but now I don’t think so anymore, since it seems to happen on things also without rules. So maybe some resource issue?

Any suggestions welcome!


10:34:27.985 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'GF_Corridor_Light2' changed from ON to OFF
10:34:27.986 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@3deb46c5': Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3491f32a[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@6bf7154c[Wrapped task = org.openhab.binding.zwave.handler.ZWaveThingHandler$1@2ef59656]] rejected from org.openhab.core.internal.common.WrappedScheduledExecutorService@49581c3e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 560]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3491f32a[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@6bf7154c[Wrapped task = org.openhab.binding.zwave.handler.ZWaveThingHandler$1@2ef59656]] rejected from org.openhab.core.internal.common.WrappedScheduledExecutorService@49581c3e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 560]
        at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.reject(Unknown Source) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(Unknown Source) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor.scheduleAtFixedRate(Unknown Source) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.startPolling(ZWaveThingHandler.java:459) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleCommand(ZWaveThingHandler.java:1220) ~[?:?]
        at jdk.internal.reflect.GeneratedMethodAccessor165.invoke(Unknown Source) ~[?:?]
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:?]
        at java.lang.reflect.Method.invoke(Unknown Source) ~[?:?]
        at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:154) [bundleFile:?]
        at org.openhab.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
        at com.sun.proxy.$Proxy4732.handleCommand(Unknown Source) [?:?]
        at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:80) [bundleFile:?]
        at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]
        at jdk.internal.reflect.GeneratedMethodAccessor164.invoke(Unknown Source) ~[?:?]
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:?]
        at java.lang.reflect.Method.invoke(Unknown Source) ~[?:?]
        at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:154) [bundleFile:?]
        at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
        at java.util.concurrent.FutureTask.run(Unknown Source) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]
        at java.lang.Thread.run(Unknown Source) [?:?]
10:34:29.047 [WARN ] [eatherflowsmartweather.util.UdpServer] - UdpServer.Listener org.openhab.binding.weatherflowsmartweather.internal.SmartWeatherUDPListenerServiceImpl$1@3357cac6 threw an exception: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@675375b7[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@4ffbdfda[Wrapped task = org.openhab.binding.weatherflowsmartweather.handler.SmartWeatherTempestHandler$1@128f46a5]] rejected from org.openhab.core.internal.common.WrappedScheduledExecutorService@49581c3e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 560]

This is on;
openjdk 11.0.11 2021-04-20
OpenJDK Runtime Environment AdoptOpenJDK-11.0.11+9 (build 11.0.11+9)
OpenJDK 64-Bit Server VM AdoptOpenJDK-11.0.11+9 (build 11.0.11+9, mixed mode)

vespaman · July 17, 2021, 8:31am

So I searched and found that other people with this issue solved it by restarting their servers, so I did just that, and it worked. Go figure.

vanja · September 11, 2021, 8:13pm

Hi,
i started having this issue today with kodi binding (kodi thing fails) and only openhab service restart helped. but then it happened again after 1 hour.

the error actually pops up in GUI when you disable enable a thing. thing looks ONLINE even though it doesnt work, so when you toggle it, it goes to COMMUNICATION_ERROR and prints the message below:

Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@14961f3[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@72279b[Wrapped task = org.openhab.binding.kodi.internal.handler.KodiHandler$$Lambda$1134/0x5b052e28@358390]] rejected from org.openhab.core.internal.common.WrappedScheduledExecutorService@d522eb[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 14251]

vespaman · September 14, 2021, 4:12pm

So, did you try to restart your entire machine (server), not just oh (service).

vanja · September 16, 2021, 5:35am

yes reboot of the machine helped.

vanja · October 7, 2021, 10:20am

Hey guys,
hope this bug will get fixed, it’s not so convenient to reboot entire server when this error happens. OH2.5 could run stable for months without restart, but with this java issue i have to reboot every few weeks…
anyone else with this kind of issues?

edit: I see the original poster uses openJDK same as me. not the same version but still almost same…
openjdk 11.0.12 2021-07-20 LTS
OpenJDK Runtime Environment Zulu11.50+19-CA (build 11.0.12+7-LTS)
OpenJDK Client VM Zulu11.50+19-CA (build 11.0.12+7-LTS, mixed mode)

is this java bug or openhab bug?

what do you suggest to do, should I try to upgrade java JDK?
or move away from openJDK to some other flavor of java, if other people don’t see this issue…

thanks

wborn · October 7, 2021, 10:47am

It’s probably a bug in an add-on that is shutting down a shared thread pool when you uninstall it or remove a Thing. What add-ons do you use?

Prevent addons from shutting down shared thread pools

opened 07:18PM - 26 Aug 21 UTC

closed 12:55PM - 13 Oct 21 UTC

janvyb

duplicate

openHAB provides addons with API for obtaining shared thread pools ([ThreadPoolM…anager](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core/src/main/java/org/openhab/core/common/ThreadPoolManager.java)), which is also used to obtain `scheduler ` property in BaseThingHandler. It's a good thing so that everyone isn't spawning their own threads and most addons use it. The problem is that nothing stops any addon from shutting down this shared pool, which has catastrophic consequences. When that happens, all addons/services which use that shared pool stop working, throwing `java.util.concurrent.RejectedExecutionException` when they try to schedule new jobs. There's no way to recover from that other than restarting openHAB, and it's also hard to diagnose since lots of things keeps working fine. I've recently encountered this problem with [miio binding](https://github.com/openhab/openhab-addons/issues/11152), but forum seems to be full of similar problems (like [this](https://community.openhab.org/t/solved-task-java-util-concurrent-scheduledthreadpoolexecutor-scheduledfuturetask-not-completed-errors/124629) or [this](https://community.openhab.org/t/telegram-binding-bot-suddenly-not-running/117876), and I'm certaint that I encountered this problem a few times myself before) and it's pretty much impossible from logs to find out what happened, because the exception is thrown from first addon that tries to use that shared pool after it was shut down. I'd propose overriding `shutdown()` and `shutdownNow()` methods on [WrappedScheduledExecutorService](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core/src/main/java/org/openhab/core/internal/common/WrappedScheduledExecutorService.java) (and maybe also on [QueueingThreadPoolExecutor](https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core/src/main/java/org/openhab/core/common/QueueingThreadPoolExecutor.java)) to either do nothing, or at least log some warning with stack trace when someone calls them. It shouldn't cause any issues since `ThreadPoolManager` isn't shutting them down and noone else should either since they are supposed to be shared.

vanja · October 7, 2021, 10:57am

thanks for the link!
yes i use miio (xiaomi) binding mentioned in your link and i might actually correlate the timing possibly while adding/removing things in there.
first i got a vaccum robot, first issue might have happened around that time, after a month it broke down so i got a replacement unit, deleted the old one, added new thing and java issue again (kodi addon stopped working and other random things (commands dont get executed via exec binding etc…)

I am done working on miio for now, i hope only to use the items without any changes…
so I will pay attention and monitor it.

wborn · October 7, 2021, 11:00am

Then you won’t have to do anything, except for maybe upgrade to 3.2.0.M3 that has the fix.

vespaman · October 7, 2021, 3:33pm

I also am using miio binding, so that would explain it for me as well. Thanks for the heads up!

remisharrock · November 14, 2021, 9:54am

Had the same issue with MIIO also! So is it a MIIO issue ? Is there an update/beta/dev version of MIIO binding, where can I find it ? Thanks !