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

Squeezebox .things file errors #1455

Closed
jhuizingh opened this issue Nov 21, 2016 · 5 comments
Closed

Squeezebox .things file errors #1455

jhuizingh opened this issue Nov 21, 2016 · 5 comments

Comments

@jhuizingh
Copy link

jhuizingh commented Nov 21, 2016

I originally reported this issue here: https://community.openhab.org/t/squeezebox-trouble-in-openhab2/17052. @kaikreuzer suggested opening an issue since the log shows a bug in the code of the binding.

I have just recently set up a squeezebox server and playing in my house and I am trying to get them connected in my openHAB2 instance. I am able to control the player well using the logitech media server web interface, as well as the Squeezer android app, so the squeezebox side of things seems to be working properly as far as I can tell. One small thing to note is that I'm running it in docker and the server it's on already had something on port 9090 so I changed port 9090 in docker to bind to host port 9091. I can successfully telnet to port 9091 on the server ip and execute squeezebox cli commands..

The trouble I'm having is that when I try to set up the squeezebox binding using a .things file, it doesn't properly connect to those items. It autodetects the server and player and puts them in the inbox in HABmin/PaperUI, but it doesn't like my configurations for some reason. Here is my things file:

Bridge squeezebox:squeezeboxserver:lms [ ipAddress="192.168.1.10", webport=9000, cliport=9091 ] {
//    Thing squeezeboxplayer myPlayer [ mac="b8:27:eb:93:17:98" ] 
}    

I commented out the player line as a test because the binding seemed to get further like this. After putting this in place, I Installed the binding in HABmin after putting this file in place. Here is the log output:


2016-11-21 08:14:07.488 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent INSTALLED - org.openhab.binding.squeezebox
2016-11-21 08:14:07.495 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent RESOLVED - org.openhab.binding.squeezebox
2016-11-21 08:14:07.503 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent STARTING - org.openhab.binding.squeezebox
2016-11-21 08:14:07.503 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent STARTED - org.openhab.binding.squeezebox
2016-11-21 08:14:07.505 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory, component.id=283, service.id=446, service.bundleid=212, service.scope=bundle} - org.openhab.binding.squeezebox
2016-11-21 08:14:07.512 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - request player job scheduled to run every 60 seconds
2016-11-21 08:14:07.512 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - registering player listener
2016-11-21 08:14:07.513 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=447, service.bundleid=212, service.scope=singleton} - org.openhab.binding.squeezebox
2016-11-21 08:14:07.516 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.UpnpDiscoveryParticipant}={component.name=org.openhab.binding.squeezebox.upnpdiscovery, component.id=284, service.id=448, service.bundleid=212, service.scope=bundle} - org.openhab.binding.squeezebox
2016-11-21 08:14:07.519 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:14:07.530 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:14:07.530 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:14:07.534 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:14:07.633 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'squeezebox:squeezeboxserver:16B1A487-DF09-4FB0-9F22-25574897F11D' to inbox.
2016-11-21 08:14:07.654 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - initializing server handler for thing org.eclipse.smarthome.core.thing.internal.BridgeImpl@a97d426c
2016-11-21 08:14:07.657 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - listener connection started to server 192.168.1.10:9091
2016-11-21 08:14:07.660 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:14:07.662 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: listen 1
2016-11-21 08:14:07.664 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - player added b8:27:eb:93:17:98 : piCorePlayer
2016-11-21 08:14:07.774 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'squeezebox:squeezeboxplayer:lms:b827eb931798' to inbox.
2016-11-21 08:14:07.774 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:93:17:98 status - 1 subscribe:10 tags:yagJlN
2016-11-21 08:14:08.211 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - disposing server handler for thing org.eclipse.smarthome.core.thing.internal.BridgeImpl@a97d426c
2016-11-21 08:14:08.212 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - setting squeeze server listener terminate flag
2016-11-21 08:14:08.212 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - initializing server handler for thing org.eclipse.smarthome.core.thing.internal.BridgeImpl@a97d426c
2016-11-21 08:14:08.212 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Squeeze Server listener exiting.
2016-11-21 08:14:08.214 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - listener connection started to server 192.168.1.10:9091
2016-11-21 08:14:08.229 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:14:08.230 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: listen 1
2016-11-21 08:14:08.231 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - player added b8:27:eb:93:17:98 : piCorePlayer
2016-11-21 08:14:08.360 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:93:17:98 status - 1 subscribe:10 tags:yagJlN
2016-11-21 08:14:17.512 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0

From what I see there, it looks like it successfully finds the squeezebox server and then even autodetects the player.

However, if I then modify the things file to uncomment the player line, here's what happens in the logs:

.things file

Bridge squeezebox:squeezeboxserver:lms [ ipAddress="192.168.1.10", webport=9000, cliport=9091 ] {
    Thing squeezeboxplayer myPlayer [ mac="b8:27:eb:93:17:98" ] 
}

Log:

2016-11-21 08:28:23.328 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'squeezebox.things' is either empty or cannot be parsed correctly!
2016-11-21 08:28:23.413 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - disposing server handler for thing org.eclipse.smarthome.core.thing.internal.BridgeImpl@a97d426c
2016-11-21 08:28:23.413 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - setting squeeze server listener terminate flag
2016-11-21 08:28:23.413 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Squeeze Server listener exiting.
2016-11-21 08:28:23.416 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'squeezebox.things'
2016-11-21 08:28:23.420 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - request player job scheduled to run every 60 seconds
2016-11-21 08:28:23.420 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - registering player listener
2016-11-21 08:28:23.422 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while calling thing handler factory 'org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory@817c10f': java.lang.IllegalStateException: BundleContext is no longer valid
java.util.concurrent.ExecutionException: java.lang.IllegalStateException: BundleContext is no longer valid
        at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_111]
        at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_111]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:186)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:79)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:63)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager.doRegisterHandler(ThingManager.java:582)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager.registerHandler(ThingManager.java:561)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager.registerHandler(ThingManager.java:541)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager.thingAdded(ThingManager.java:439)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:217)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutAddedElement(ThingRegistryImpl.java:136)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutAddedElement(ThingRegistryImpl.java:1)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.registry.AbstractRegistry.added(AbstractRegistry.java:123)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:51)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:70)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutAddedElement(AbstractProvider.java:74)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.access$8(GenericThingProvider.java:1)[131:org.eclipse.smarthome.model.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$11.apply(GenericThingProvider.java:696)[131:org.eclipse.smarthome.model.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$11.apply(GenericThingProvider.java:1)[131:org.eclipse.smarthome.model.thing:0.9.0.201611181452]
        at org.eclipse.xtext.xbase.lib.IteratorExtensions.forEach(IteratorExtensions.java:363)[144:org.eclipse.xtext.xbase.lib:2.9.2]
        at org.eclipse.xtext.xbase.lib.IterableExtensions.forEach(IterableExtensions.java:333)[144:org.eclipse.xtext.xbase.lib:2.9.2]
        at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.modelChanged(GenericThingProvider.java:699)[131:org.eclipse.smarthome.model.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:207)[120:org.eclipse.smarthome.model.core:0.9.0.201611181452]
        at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:99)[120:org.eclipse.smarthome.model.core:0.9.0.201611181452]
        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:267)[120:org.eclipse.smarthome.model.core:0.9.0.201611181452]
        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.access$1(FolderObserver.java:261)[120:org.eclipse.smarthome.model.core:0.9.0.201611181452]
        at org.eclipse.smarthome.model.core.internal.folder.FolderObserver$WatchQueueReader.processWatchEvent(FolderObserver.java:142)[120:org.eclipse.smarthome.model.core:0.9.0.201611181452]
        at org.eclipse.smarthome.core.service.AbstractWatchQueueReader.run(AbstractWatchQueueReader.java:95)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at java.lang.Thread.run(Thread.java:745)[:1.8.0_111]
Caused by: java.lang.IllegalStateException: BundleContext is no longer valid
        at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:983)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:463)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:482)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory.registerSqueezeBoxPlayerDiscoveryService(SqueezeBoxHandlerFactory.java:93)[198:org.openhab.binding.squeezebox:2.0.0.201611181914]
        at org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory.createHandler(SqueezeBoxHandlerFactory.java:63)[198:org.openhab.binding.squeezebox:2.0.0.201611181914]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory.registerHandler(BaseThingHandlerFactory.java:98)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:586)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:1)[103:org.eclipse.smarthome.core.thing:0.9.0.201611181452]
        at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:177)[96:org.eclipse.smarthome.core:0.9.0.201611181452]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_111]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_111]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_111]
        ... 1 more

In this log I first see a message that the .things file can't be parsed correctly. If there's an error in the syntax, I don't know how to fix it because I can't find any good examples that are different than this one.

After that error, there is an exception from the binding. Not sure if that's caused by the syntax error or if it's unrelated.

Some additional information. If I restart openhab with the above .things file containing both the bridge/server entry AND the player entry, there is a different result where it at least partially is able to recognize them. Here is the log of that:

2016-11-21 08:35:45.479 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent INSTALLED - org.openhab.binding.squeezebox
2016-11-21 08:35:45.515 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent RESOLVED - org.openhab.binding.squeezebox
2016-11-21 08:35:45.525 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent STARTING - org.openhab.binding.squeezebox
2016-11-21 08:35:45.526 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent STARTED - org.openhab.binding.squeezebox
2016-11-21 08:35:45.604 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - request player job scheduled to run every 60 seconds
2016-11-21 08:35:45.609 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - registering player listener
2016-11-21 08:35:45.612 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=329, service.bundleid=214, service.scope=singleton} - org.openhab.binding.squeezebox
2016-11-21 08:35:45.631 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory, component.id=199, service.id=328, service.bundleid=214, service.scope=bundle} - org.openhab.binding.squeezebox
2016-11-21 08:35:45.639 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.641 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - initializing server handler for thing org.eclipse.smarthome.core.thing.internal.BridgeImpl@a97d426c
2016-11-21 08:35:45.669 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - listener connection started to server 192.168.1.10:9091
2016-11-21 08:35:45.693 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:35:45.695 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: listen 1
2016-11-21 08:35:45.696 [DEBUG] [ebox.handler.SqueezeBoxPlayerHandler] - updating player status to match server status of ONLINE
2016-11-21 08:35:45.702 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - player added b8:27:eb:93:17:98 : piCorePlayer
2016-11-21 08:35:45.733 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.734 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.740 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.743 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.748 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.748 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Discovered a Logitech Media Server [21d97a083044] thing with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.752 [DEBUG] [SqueezeBoxServerDiscoveryParticipant] - Created a DiscoveryResult for device 'Logitech Media Server [21d97a083044]' with UDN '16B1A487-DF09-4FB0-9F22-25574897F11D'
2016-11-21 08:35:45.828 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'squeezebox:squeezeboxplayer:lms:b827eb931798' to inbox.
2016-11-21 08:35:45.829 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:93:17:98 status - 1 subscribe:10 tags:yagJlN
2016-11-21 08:35:46.150 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'squeezebox:squeezeboxserver:16B1A487-DF09-4FB0-9F22-25574897F11D' to inbox.
2016-11-21 08:35:46.151 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.UpnpDiscoveryParticipant}={component.name=org.openhab.binding.squeezebox.upnpdiscovery, component.id=200, service.id=330, service.bundleid=214, service.scope=bundle} - org.openhab.binding.squeezebox
2016-11-21 08:35:46.598 [DEBUG] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer disposed.
2016-11-21 08:35:46.599 [DEBUG] [ebox.handler.SqueezeBoxPlayerHandler] - updating player status to match server status of ONLINE
2016-11-21 08:35:47.517 [INFO ] [core.karaf.internal.FeatureInstaller] - Installed 'openhab-binding-squeezebox'
2016-11-21 08:35:55.605 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:36:55.606 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:37:55.606 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:38:55.607 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:39:10.843 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'squeezebox.items'
2016-11-21 08:39:10.851 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.852 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.855 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.856 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.873 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.880 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:39:10.880 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'squeezebox.items'
2016-11-21 08:39:55.608 [DEBUG] [ebox.handler.SqueezeBoxServerHandler] - Sending command: players 0
2016-11-21 08:40:26.197 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'squeezebox.items'
2016-11-21 08:40:26.201 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.203 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.205 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.206 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.214 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.215 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.217 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH
2016-11-21 08:40:26.217 [INFO ] [ebox.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:lms:myPlayer has no server configured, ignoring command: REFRESH

It seems to be "correctly" parsing the .things file and making the items, but the player item isn't working. The log shows that it is disposing of the myPlayer thing for some reason.

The above log is with the following items attached to the things in a squeezebox.items file.

Group gSqueezebox

Number myPlayerVolume     "My Player Volume [%d]"         (gSqueezebox) {channel="squeezebox:squeezeboxplayer:lms:myPlayer:volume"}
Player myPlayerController "My Player Control"              (gSqueezebox) {channel="squeezebox:squeezeboxplayer:lms:myPlayer:control"}
@kaikreuzer
Copy link
Member

Having had a closer look at the Squeezebox code, I am not that sure anymore that the bug is within in.
The BundleContext is no longer valid message means that somehow the bundleContext is outdated - but this is set and unset by the BaseThingHandlerFactory, so the issue might rather be within the core framework. @sbussweiler, can you make sense out of that?

@jmccoy555
Copy link

Hi all, as I said in the community post referenced above, I am having what appears to be the same issue since update to the latest snapshot from #580 when this this was working as expected when configure through the .thing file.

Despite this issue, I have just noticed that the title is still being update within openhab when controlled directly by the lms.

More than happy to help with any testing or can provide further details.

@sbussweiler
Copy link

@jhuizingh

I had a look on your log entries.

  • In the first log output I have seen that the server bridge handler is initialized and immediately disposed afterwards. But I can not see why the handler is disposed so far.
  • The second log is really strange. An IllegalStateException with BundleContext is no longer valid is a sign that the BundleContext reference has been manipulated. Could it be that your bundle is shutting down in the meanwhile? The BundleContext is added in the activate() method of your factory. In that case there were no code changes in the past.
  • In the third log the bridge handler is initialized, the thing handler is initialized. The strange behavior is that the thing handler is dispose immediately. But I can not realize why.

Means; I need additional logs. Can you enable debug logging for org.eclipse.smarthome.* ? I need the logs of your scenarios above:

  • Add bridge and thing to your *.thing file and start openHAB
  • Add only the bridge to your *.thing file, start openHAB, add the thing to your *.thing.file

@jhuizingh
Copy link
Author

@sbussweiler, thanks for looking into that. I will try and get you those logs.

Some additional info that may or may not help: I was able to get openhab2 up and running within eclipse according to the IDE Setup guide and the bridge and player seemed to initialize properly.

I'll work on those logs and get them to you ASAP. Thanks!

@jhuizingh
Copy link
Author

Hmm, the few items I have hooked up to the squeezebox player seem to be working right now. Maybe it was other configuration elsewhere in openhab that was in a strange state. I will go ahead and close this right now, and if I run across the error again I will repost the bug or reopen this one as appropriate. Thanks for the help.

markus7017 pushed a commit to markus7017/openhab-addons that referenced this issue Aug 12, 2023
Example with item Switch Kitchen_Light in the example is not correct for current binding version.
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

4 participants