[Update] It appears this issue was a result of a problem with another binding.
[Original Post]
I’ve been using openHAB for years with much success but every so often, especially after an upgrade I run into a snag.
Yesterday my Alexa devices said my openHAB devices were not responding so I SSHed in and did an update. It took forever for my Pine64 to restart. I thought I had a bad MicroSD card. After one more try and giving it a lot of time, I finally had a system working but from what I could tell my Z-wave devices were really delayed. After things seemed to be working again I just went to bed for the night.
Tonight my normal sunset rules didn’t seem to trigger so I noticed I seemed to be having a problem. Funny thing is I think I used my Alexa to successfully control some z-wave devices just a few hours earlier. Now when I try to use Alexa or my openHAB android app I get the follwing in my log viewer. I’m not understanding what is the problem but I see the words Java and I seem to recall the point at which I got to Java when I was upgrading the openHAB software yesterday is where is stopped for a long time.
Any suggestions?
2020-06-14 21:25:33.321 [ome.event.ItemCommandEvent] - Item ‘OD_Landscape’ received command ON
2020-06-14 21:25:33.353 [nt.ItemStatePredictedEvent] - OD_Landscape predicted to become ON
2020-06-14 21:25:33.396 [vent.ItemStateChangedEvent] - OD_Landscape changed from OFF to ON
==> /var/log/openhab2/openhab.log <==
2020-06-14 21:25:33.374 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method ‘ThingHandler.handleCommand()’ on ‘org.openhab.binding.zwave.handler.ZWaveThingHandler@f0473b’: Timer already cancelled.
java.lang.IllegalStateException: Timer already cancelled.
at java.util.Timer.sched(Timer.java:397) ~[?:1.8.0_222]
at java.util.Timer.schedule(Timer.java:208) ~[?:1.8.0_222]
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager.startTransactionTimer(ZWaveTransactionManager.java:1010) ~[?:?]
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager.addTransactionToQueue(ZWaveTransactionManager.java:381) ~[?:?]
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager.queueTransactionForSend(ZWaveTransactionManager.java:337) ~[?:?]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.enqueue(ZWaveController.java:505) ~[?:?]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.sendData(ZWaveController.java:889) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveControllerHandler.sendData(ZWaveControllerHandler.java:472) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleCommand(ZWaveThingHandler.java:1191) ~[?:?]
at sun.reflect.GeneratedMethodAccessor425.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
at com.sun.proxy.$Proxy1938.handleCommand(Unknown Source) [?:?]
at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74) [bundleFile:?]
at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]
at sun.reflect.GeneratedMethodAccessor424.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]