OH2.1 and Harmonyhub

idkpmiller · July 3, 2017, 6:06am

I have recent installed the Openhabian 2.1 image on my RPi, I have then restored my settings etc… and found the only issue was at some stage my Harmony Hub had got an IP address that I was not expecting, I have two DHCP servers on my network and I normally set the fixed addresses on both servers so that they always get allocated. On this occasion I made a mistake and one DHCP server did not have the static entry so allocated a standard DHCP pool address. this caused a situation where in Paperui Things one screen showed the static entry while the other under show properties showed the DHCP pool address. Sorting out the static IP address on the DHCP servers and rebooting the harmony box followed by the RPi did not help the two different addresses still showed, except now the Harmony binding would no longer poweroff devices…

The log entry below indicates an issue, can anyone suggest how I rectify the problem, I have already removed all things and uninstalled the binding then reinstalled it all again.

2017-07-03 17:09:17.680 [ItemCommandEvent          ] - Item 'tv' received command OFF
==> /var/log/openhab2/openhab.log <==
2017-07-03 17:09:17.714 [INFO ] [smarthome.model.script.harmony.rules] - TV turn OFF
2017-07-03 17:09:17.717 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occurred while calling handler: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@f9d37e rejected from java.util.concurrent.ScheduledThreadPoolExecutor@1a51c03[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
java.util.concurrent.ExecutionException: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@f9d37e rejected from java.util.concurrent.ScheduledThreadPoolExecutor@1a51c03[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.executeDirectly(SafeMethodCaller.java:220)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:189)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.thing.internal.ThingManager.receiveCommand(ThingManager.java:374)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
	at org.eclipse.smarthome.core.items.events.AbstractItemEventSubscriber.receive(AbstractItemEventSubscriber.java:47)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:192)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:1)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.b5]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@f9d37e rejected from java.util.concurrent.ScheduledThreadPoolExecutor@1a51c03[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)[:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326)[:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533)[:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:622)[:1.8.0_121]
	at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:668)[:1.8.0_121]
	at org.openhab.binding.harmonyhub.handler.HarmonyHubHandler.pressButton(HarmonyHubHandler.java:334)[238:org.openhab.binding.harmonyhub:2.1.0]
	at org.openhab.binding.harmonyhub.handler.HarmonyDeviceHandler.handleCommand(HarmonyDeviceHandler.java:97)[238:org.openhab.binding.harmonyhub:2.1.0]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:377)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.executeDirectly(SafeMethodCaller.java:218)[98:org.eclipse.smarthome.core:0.9.0.b5]
	... 12 more
==> /var/log/openhab2/events.log <==
2017-07-03 17:09:17.736 [ItemCommandEvent          ] - Item 'HarmonyLivingRoomLGTV' received command PowerOff
2017-07-03 17:09:19.251 [ItemStateChangedEvent     ] - NetworkDevice1921680252_Online changed from OFF to ON
2017-07-03 17:09:19.397 [ItemStateChangedEvent     ] - CurrentTime changed from 2017-07-03T17:08:31.286+1200 to 2017-07-03T17:09:19.380+1200
2017-07-03 17:09:19.410 [ItemStateChangedEvent     ] - LocalTime_Date changed from 2017-07-03T17:08:31.286+1200 to 2017-07-03T17:09:19.380+1200
2017-07-03 17:09:36.997 [ItemStateChangedEvent     ] - NetworkDevice1921680165_Online changed from ON to OFF
==> /var/log/openhab2/openhab.log <==
2017-07-03 17:09:37.094 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/event-stream, type=class org.glassfish.jersey.media.sse.OutboundEvent, genericType=class org.glassfish.jersey.media.sse.OutboundEvent.
==> /var/log/openhab2/events.log <==
2017-07-03 17:09:39.277 [ItemStateChangedEvent     ] - NetworkDevice1921680164_Online changed from ON to OFF.

wborn · July 4, 2017, 1:16am

I can reproduce your issue as follows:

Edit and save Harmony Hub configuration
Send pressButton command

Most likely the issue is that when the configuration is changed the buttonExecutor threadpool is stopped (in dispose()) but never restarted (in initialize()). WDYT @digitaldan?

So a workaround that will probably work for now is:

Edit and save Harmony Hub configuration
Restart openHAB
Send pressButton commands all you like
If for some reason you again want to edit/update the Harmony Hub configuration again restart openHAB after it

idkpmiller · July 4, 2017, 6:42am

I must confess I did not hold out much help as I had already rebooted the RPi earlier in the troubleshooting exercise.
However, tested made sure I was still getting the error output, which I was then I rebooted and You were Correct! it now works again.

Do I need to raise a bug report somewhere to get this looked into?

Thanks for your help much appreciated.

Paul

digitaldan · July 4, 2017, 4:26pm

Oh, yuck, yes that looks like my handywork I would be happy to submit a fix unless @wborn you have already done so.

wborn · July 4, 2017, 4:28pm

I haven’t prepared a fix yet, so it would be nice if you can create one!

digitaldan · July 4, 2017, 4:28pm

Sounds, good, will do.

idkpmiller · October 19, 2017, 9:21pm

can some advise if this has been fixed and available for use? I am still seeing the issue.
what version is the fix included?

Thanks

Paul