Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bose SoundTouch Binding] Exceptions during start and stop, only volume channel working #4420

Closed
UdoWeberJR opened this issue Dec 21, 2018 · 3 comments

Comments

@UdoWeberJR
Copy link

Hi,

when I start openHAB and also when I explizit start the stopped Bose SoundTouch Binding I see the same exception (see below) multiple times. As a result only the volume channel seems to get the current values of the powered on SoundTouch 300.

Also when I stop the binding via the karaf console I get a Warning "Couldn't stop Thread".

I attached a log file with level set to TRACE for Bose SoundTouch Binding, hope that helps.

Let me know if you need anything else.
Greets Udo

Bose Trace Log.txt

Logs

Starting (X-out mac and ip)

2018-12-21 20:11:25.278 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: Blocking message pending 10000 for BLOCKING
java.lang.IllegalStateException: Blocking message pending 10000 for BLOCKING
	at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.lockMsg(WebSocketRemoteEndpoint.java:130) ~[?:?]
	at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendString(WebSocketRemoteEndpoint.java:386) ~[?:?]
	at org.eclipse.smarthome.binding.bosesoundtouch.internal.CommandExecutor.getInformations(CommandExecutor.java:123) ~[?:?]
	at org.eclipse.smarthome.binding.bosesoundtouch.handler.BoseSoundTouchHandler.handleCommand(BoseSoundTouchHandler.java:172) ~[?:?]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:233) ~[?:?]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:300) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
	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) [?:?]

Followed by some repeating item changes:

2018-12-21 20:11:25.831 [hingStatusInfoChangedEvent] - 'bosesoundtouch:300:9884E304XXXX' changed from UNINITIALIZED to INITIALIZING

2018-12-21 20:11:25.832 [hingStatusInfoChangedEvent] - 'bosesoundtouch:300:9884E304XXXX' changed from INITIALIZING to ONLINE

2018-12-21 20:11:25.835 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_Volume changed from NULL to 20

2018-12-21 20:11:25.837 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_RateEnabled changed from NULL to OFF

2018-12-21 20:11:25.854 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_SkipEnabled changed from NULL to OFF

2018-12-21 20:11:25.859 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_SkipPreviousEnabled changed from NULL to OFF

2018-12-21 20:11:25.868 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:25.872 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_OperationMode changed from NULL to STANDBY

2018-12-21 20:11:25.875 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_Power changed from NULL to OFF

2018-12-21 20:11:25.920 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:25.946 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.022 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.077 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.221 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.231 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.305 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.308 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.317 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.342 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.348 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.352 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.358 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.361 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

2018-12-21 20:11:26.364 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from  to NULL

2018-12-21 20:11:26.370 [vent.ItemStateChangedEvent] - Speaker_Bose_SoundTouch_300_nowPlayingItemName changed from NULL to 

Stopping the binding via karaf console

2018-12-21 20:19:21.410 [hingStatusInfoChangedEvent] - 'bosesoundtouch:300:9884E304XXXX' changed from ONLINE to UNINITIALIZED

==> /var/log/openhab2/openhab.log <==

2018-12-21 20:19:22.444 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - QueuedThreadPool[WebSocketClient@9768421]@190b413{STOPPING,8<=8<=200,i=0,q=3}[org.eclipse.jetty.util.thread.TryExecutor$$Lambda$116/12917523@19a720d] Couldn't stop Thread[WebSocketClient@9768421-140,5,main]

==> /var/log/openhab2/events.log <==

2018-12-21 20:19:22.459 [hingStatusInfoChangedEvent] - 'bosesoundtouch:300:9884E304XXXX' changed from UNINITIALIZED to OFFLINE (COMMUNICATION_ERROR): Binding shutdown

2018-12-21 20:19:22.474 [hingStatusInfoChangedEvent] - 'bosesoundtouch:300:9884E304XXXX' changed from OFFLINE (COMMUNICATION_ERROR): Binding shutdown to UNINITIALIZED (HANDLER_MISSING_ERROR)

For completeness here my thing file:

Thing bosesoundtouch:300:9884E304XXXX "Bose SoundTouch 300" @ "Living room" [host="192.168.XXX.XX", macAddress="9884E304XXXX"]

Enviroment

Bose Software Version 20.0.6
Binding = BoseSoundTouch Binding 0.10.0.oh240
Raspbian GNU/Linux 9 (stretch)
Kernel = Linux 4.14.79-v7+
Platform = Raspberry Pi 3 Model B Rev 1.2
OpenHAB = openhab 2.4.0-1 (Release Build)

@wborn
Copy link
Member

wborn commented Dec 21, 2018

Thanks for reporting the issue Udo.
Can you create an issue for this in the Eclipse SmartHome project issue tracker instead?
That's the repository where the Bose Soundtouch code is maintained.

@wborn wborn closed this as completed Dec 21, 2018
@UdoWeberJR
Copy link
Author

Sure, sorry, didn't realize that fact.

@wborn
Copy link
Member

wborn commented Dec 21, 2018

Thanks for creating eclipse-archived/smarthome#6714 !

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants