[SOLVED] Squeezebox Binding Openhab 2.5 Problems

Hello Everyone,

I’ve read a few threads about errors that people had with this binding, but this was not very promising…

I configured the binding manually with files.

The things file: squeeze.things

Bridge squeezebox:squeezeboxserver:94xxxxxxxx45 "Squeezebox - Server Musix" [ ipAddress="192.168.xxx.xxx", webport=9000, cliport=9090, userId="xxxxxxx", password="xxxxxxx" ] {
    Thing squeezeboxplayer  0axxxxxxxx68    "Squeezebox - 1"     [ mac="0A:XX:XX:XX:XX:68", notificationTimeout=30, notificationVolume=35 ]
    Thing squeezeboxplayer  baxxxxxxxx28    "Squeezebox - 2"      [ mac="BA:XX:XX:XX:XX:28", notificationTimeout=30, notificationVolume=35 ]
    Thing squeezeboxplayer  24xxxxxxxxea    "Squeezebox - 3"     [ mac="24:XX:XX:XX:XX:EA", notificationTimeout=30, notificationVolume=35 ]
    Thing squeezeboxplayer  fexxxxxxxxbe    "Squeezebox - 4"   [ mac="FE:XX:XX:XX:XX:BE", notificationTimeout=30, notificationVolume=35 ]
    Thing squeezeboxplayer  b8xxxxxxxx44    "Squeezebox - 5"    [ mac="B8:XX:XX:XX:XX:44", notificationTimeout=30, notificationVolume=35 ]
}

A part of my items file: squeeze.items

...
// LivingRoom
Player  SqueezeLivingRoomControl        "Livingroom"                    (gSqueeze)  { channel="squeezebox:squeezeboxplayer:xxx:xxx:control" }
Dimmer  SqueezeLivingRoomVolume         "Volume [%s]"                   (gSqueeze)  { channel="squeezebox:squeezeboxplayer:xxx:xxx:volume" }
Number  SqueezeLivingRoomCurrPlaytime   "Playing Time [JS(mmss.js):%s]" (gSqueeze)  { channel="squeezebox:squeezeboxplayer:xxx:xxx:currentPlayingTime" }
Number  SqueezeLivingRoomPlaylistIndex  "Playlist Index"                (gSqueeze)  { channel="squeezebox:squeezeboxplayer:xxx:xxx:playListIndex" }
Number  SqueezeLivingRoomDuration       "Duration [JS(mmss.js):%s]"     (gSqueeze)  { channel="squeezebox:squeezeboxplayer:xxx:xxx:duration" }
...

Without openhab all my squeezeboxes and the squeezeserver act like supposed, I can control them via webinterface and android app.

In PaperUI the server and the players are shown as ONLINE but when I try to control a player via my sitemap or even if the player is started from the webinterface of squeezeserver none of the items get updated… no Artist, no Title, no Cover… It seems to behave like there are OFFLINE… I don’t really get it ???

had a look at my logs but the items get fired from my sitemap when I click them but none of my players are recognizing anything I do…

In other words: Everythings looks fine but nothing’s working );

Hope someone has any further ideas on that - I’ll take a rest…
If you need additional log info please feel free to bother me :wink:

thanks in advance,

Dan

Hmm. This might suggest the items aren’t linked to the channels correctly.

In the console, run this command, then make sure the channels in your item definitions match.

smarthome:things list | grep squeezebox

:wink: I had to figure out how to open the console first… but here you are - I wasn’t using it before

openhab> smarthome:things list | grep squeezebox
squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68 (Type=Thing, Status=ONLINE, Label=Squeezebox - 1, Bridge=squeezebox:squeezeboxserver:94xxxxxxxx45)
squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe (Type=Thing, Status=ONLINE, Label=Squeezebox - 2, Bridge=squeezebox:squeezeboxserver:94xxxxxxxx45)
squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44 (Type=Thing, Status=ONLINE, Label=Squeezebox - 3, Bridge=squeezebox:squeezeboxserver:94xxxxxxxx45)
squeezebox:squeezeboxserver:94xxxxxxxx45 (Type=Bridge, Status=ONLINE, Label=Squeezebox - Server Musix, Bridge=null)
squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28 (Type=Thing, Status=ONLINE, Label=Squeezebox - 4, Bridge=squeezebox:squeezeboxserver:94xxxxxxxx45)
squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea (Type=Thing, Status=ONLINE, Label=Squeezebox - 5, Bridge=squeezebox:squeezeboxserver:94xxxxxxxx45)

Sorry no luck also this looks beautiful…

Dan

edit: btw I’m running 2.5 build 1492

Just another suggestion… is it possible that the squeezebox mac adresses are not the same as the physical mac-adresses shown in my router?? And is there a way to see which mac-adresses are stored in LMS or are the squeezeboxes identified another way by LMS itself?

I think I need a little research on this…

Ok, now that you know how to get into the console… :smile:

Let’s put the binding into debug mode. In the console, run this:

log:set DEBUG org.openhab.binding.squeezebox

Then try to operate the players using the sitemap. You should see evidence of this in openhab.log.

You take it out of debug mode by running this:

log:set INFO org.openhab.binding.squeezebox

Possible, but not likely. Check the Information tab in the LMS Settings. It should show you the MAC addresses of the players.

Ok done that… will try it out and post back

Edit:

2019-01-17 22:15:15.228 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: 0Axxxxxxxx68 power 0
2019-01-17 22:15:22.528 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: 0Axxxxxxxx68 power 1
2019-01-17 22:15:34.344 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: players 0

Seems that the binding is not able to find any players…

Try stopping and starting the binding. That will show the initialization of the server and player handlers. Maybe that will provide a clue.

bundle:stop org.openhab.binding.squeezebox
bundle:start org.openhab.binding.squeezebox

BTW, this doesn’t mean there are no players. It’s just the command the binding uses to discover players.

Ahh ok misinterpreted that…

Log

2019-01-17 22:24:26.140 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:46:8a:44 status - 1 subscribe:10 tags:yagJlNKjc
2019-01-17 22:24:26.141 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=526, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:24:26.144 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=527, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:24:26.147 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=528, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:24:26.168 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44 initialized.
2019-01-17 22:24:26.169 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28 initialized.
2019-01-17 22:24:26.172 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe initialized.
2019-01-17 22:24:26.179 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68 initialized.
2019-01-17 22:24:26.180 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea initialized.
2019-01-17 22:24:26.203 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=522, service.bundleid=277, service.scope=bundle, component.name=org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory, component.id=349} - org.openhab.binding.squeezebox

==> /var/log/openhab2/events.log <==
2019-01-17 22:24:26.178 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:24:26.181 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44' changed from INITIALIZING to ONLINE
2019-01-17 22:24:26.181 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:24:26.182 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28' changed from INITIALIZING to ONLINE
2019-01-17 22:24:26.183 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:24:26.183 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:24:26.185 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:24:26.188 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe' changed from INITIALIZING to ONLINE
2019-01-17 22:24:26.189 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68' changed from INITIALIZING to ONLINE
2019-01-17 22:24:26.189 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea' changed from INITIALIZING to ONLINE

everything seems to run - I don’t get it…

Edit: Just another dumb question are the items automatically updated if the players are running a playlist?

Is that all you see in openhab.log? Can you post what you see starting from this line?

BundleEvent STARTING - org.openhab.binding.squeezebox

Yes, album, artist, title, coverart, etc. all are updated.

sorry on first try done it with the same console so the log was cut…
here are the full lines

2019-01-17 22:36:35.320 [DEBUG] [org.openhab.binding.squeezebox      ] - BundleEvent STARTED - org.openhab.binding.squeezebox
2019-01-17 22:36:35.337 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.type.DynamicStateDescriptionProvider, org.openhab.binding.squeezebox.internal.SqueezeBoxStateDescriptionOptionsProvider}={service.id=529, service.bundleid=277, service.scope=bundle, component.name=org.openhab.binding.squeezebox.internal.SqueezeBoxStateDescriptionOptionsProvider, component.id=350} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.341 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.UpnpDiscoveryParticipant}={service.id=530, service.bundleid=277, service.scope=bundle, component.name=org.openhab.binding.squeezebox.internal.discovery.SqueezeBoxServerDiscoveryParticipant, component.id=351} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.348 [DEBUG] [SqueezeBoxPlayerDiscoveryParticipant] - Request player job scheduled to run every 60 seconds
2019-01-17 22:36:35.351 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=532, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.356 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - initializing server handler for thing squeezebox:squeezeboxserver:94xxxxxxxx45

==> /var/log/openhab2/events.log <==
2019-01-17 22:36:35.356 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxserver:94xxxxxxxx45' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-01-17 22:36:35.358 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2019-01-17 22:36:35.360 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2019-01-17 22:36:35.361 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2019-01-17 22:36:35.362 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)
2019-01-17 22:36:35.362 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

Hmm. Do you see a line that looks like this? It should be right after the last line you posted above.

2019-01-17 16:31:18.991 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - listener connection started to server 192.168.xx.xx:9090

and here the rest of the log

==> /var/log/openhab2/openhab.log <==
2019-01-17 22:36:35.369 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - listener connection started to server 192.168.15.160:9090

==> /var/log/openhab2/events.log <==
2019-01-17 22:36:35.375 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxserver:94c691131d45' changed from INITIALIZING to ONLINE

==> /var/log/openhab2/openhab.log <==
2019-01-17 22:36:35.376 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=534, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.377 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=535, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.382 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=533, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.383 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Logging into Squeeze Server using userId=
2019-01-17 22:36:35.384 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: login squeeze T
2019-01-17 22:36:35.385 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: players 0
2019-01-17 22:36:35.386 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: favorites items 0 100
2019-01-17 22:36:35.387 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: listen 1
2019-01-17 22:36:35.456 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=536, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.466 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:46:8a:44 status - 1 subscribe:10 tags:yagJlNKjc
2019-01-17 22:36:35.475 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list
2019-01-17 22:36:35.476 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list
2019-01-17 22:36:35.476 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list
2019-01-17 22:36:35.477 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:2xxxxxxxxea initialized.

==> /var/log/openhab2/events.log <==
2019-01-17 22:36:35.478 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

==> /var/log/openhab2/openhab.log <==
2019-01-17 22:36:35.456 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.audio.AudioSink}={service.id=537, service.bundleid=277, service.scope=singleton} - org.openhab.binding.squeezebox
2019-01-17 22:36:35.483 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68 initialized.
2019-01-17 22:36:35.514 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28 initialized.
2019-01-17 22:36:35.515 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44 initialized.
2019-01-17 22:36:35.530 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - player thing squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe initialized.

==> /var/log/openhab2/events.log <==
2019-01-17 22:36:35.532 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:24xxxxxxxxea' changed from INITIALIZING to ONLINE
2019-01-17 22:36:35.533 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:36:35.534 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:36:35.536 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:36:35.537 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:0axxxxxxxx68' changed from INITIALIZING to ONLINE
2019-01-17 22:36:35.539 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING
2019-01-17 22:36:35.539 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:baxxxxxxxx28' changed from INITIALIZING to ONLINE
2019-01-17 22:36:35.540 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:b8xxxxxxxx44' changed from INITIALIZING to ONLINE
2019-01-17 22:36:35.541 [hingStatusInfoChangedEvent] - 'squeezebox:squeezeboxplayer:94xxxxxxxx45:fexxxxxxxxbe' changed from INITIALIZING to ONLINE

==> /var/log/openhab2/openhab.log <==
2019-01-17 22:36:35.545 [DEBUG] [org.openhab.binding.squeezebox      ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=531, service.bundleid=277, service.scope=bundle, component.name=org.openhab.binding.squeezebox.internal.SqueezeBoxHandlerFactory, component.id=352} - org.openhab.binding.squeezebox

sorry

Edit: yes its just the first lines

2019-01-17 22:36:35.475 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list
2019-01-17 22:36:35.476 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list
2019-01-17 22:36:35.476 [DEBUG] [rnal.handler.SqueezeBoxPlayerHandler] - Player null updating favorites list

Hmm. That doesn’t look right. That null should be the MAC addresses of the players.

BTW, I think your id/password are in the log, so you might want to edit those out of your post.

puhh hm no idea whats happening - really no idea…

edited my post…

This is a fresh install I made a month ago… running debian stretch on a intel nuc.
the binding is installed through PaperUI and everything looks fine when I created the bridge & things & items… don’t know what can cause such an error…

Me either. It’s usually not this hard… :confused:

Well, I can see that the binding is getting a connection to your LMS server, and is sending commands to the LMS. It seems to be something with how the players are defined.

One thing you could try…

Instead of configuring the things using the things file, trying adding them from the inbox using Paper UI. Make sure to adjust your item definitions, too. This will eliminate one variable.

Also, would you mind PM’ing me your exact things and items file contents for the squeezeboxes?

Ok commented out the things and restarted openhab service…
I’ll be back in a minute…

btw you received my pm