[Squeezebox] playSound vs LMS 7.9.1 on piCorePlayer / lost connection

So, I see where it’s saving the volume for both players.

2018-12-08 08:45:11.035 [DEBUG] [ternal.handler.SqueezeBoxPlayerState] - Cur State: vol=60, mut=NOT MUTED, pwr=ON, stp=STOPPED, ctl=PAUSED, shf=OFF, rpt=OFF, tix=60, tnm=61, tim=0
2018-12-08 08:45:11.066 [DEBUG] [ternal.handler.SqueezeBoxPlayerState] - Cur State: vol=90, mut=NOT MUTED, pwr=ON, stp=STOPPED, ctl=PAUSED, shf=OFF, rpt=OFF, tix=0, tnm=0, tim=0

Then, when the notifications are done, it’s restoring the volume for both players.

2018-12-08 08:45:13.920 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:0f:fa:a9 mixer volume 90
2018-12-08 08:45:15.125 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:e2:3a:a3 mixer volume 60

Then almost 13 seconds later, with nothing else occurring during that 13 seconds, the volume’s being set to 0 for player b8:27:eb:0f:fa:a9

2018-12-08 08:45:26.821 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:0f:fa:a9 mixer volume 0

I have no plausible explanation for why that’s happening.

The only I can do is to enable TRACE and wait for this event again.

Yeah, maybe that will shed some light on what’s going on.

BTW, the fix for the connection issue is in the latest snapshot builds.

1 Like

openhablog1.log.zip.xml (523.7 KB)
Can you look on this log? I believe something goes wrong here.
With TRACE enabled the log is very long, however in this part it is the last time I see “Cur State: vol=90” next time in log “Cur State: vol=0”.

Which version are you running? The version with the fix shouldn’t be throwing this exception anymore.

2018-12-10 07:07:21.661 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - **SqueezeServerListener got unexpected exception: null
java.util.ConcurrentModificationException: null
	at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:909) ~[?:?]
	at java.util.ArrayList$Itr.next(ArrayList.java:859) ~[?:?]
	at org.openhab.binding.squeezebox.internal.handler.SqueezeBoxServerHandler.updatePlayer(SqueezeBoxServerHandler.java:1010) ~[191:org.openhab.binding.squeezebox:2.4.0.201811121430]
	at org.openhab.binding.squeezebox.internal.handler.SqueezeBoxServerHandler.access$8(SqueezeBoxServerHandler.java:1008) ~[191:org.openhab.binding.squeezebox:2.4.0.201811121430]
	at org.openhab.binding.squeezebox.internal.handler.SqueezeBoxServerHandler$SqueezeServerListener.handlePlaylistMessage(SqueezeBoxServerHandler.java:863) ~[191:org.openhab.binding.squeezebox:2.4.0.201811121430]
	at org.openhab.binding.squeezebox.internal.handler.SqueezeBoxServerHandler$SqueezeServerListener.handlePlayerUpdate(SqueezeBoxServerHandler.java:577) ~[191:org.openhab.binding.squeezebox:2.4.0.201811121430]
	at org.openhab.binding.squeezebox.internal.handler.SqueezeBoxServerHandler$SqueezeServerListener.run(SqueezeBoxServerHandler.java:444) [191:org.openhab.binding.squeezebox:2.4.0.201811121430]

Hmm. Strange. I have 2 of them 2.4.0.M7 and 2.4.0.201811150132. I was sure that I have removed 2.4.0.201811150132. 2.4.0.M7 is the actual snapshot?

M7 is a milestone release. Milestone releases are done about monthly (snapshots are daily).

M7 should have the fix, and it definitely doesn’t produce some of the debug messages in the log file you posted above. If the squeezebox binding is not in your addons directory, you may need to stop OH, then clear tmp and cache.

Look in the console to see what’s running.

list -s | grep squeeze

OK, it looks like for some reason there are still 2 addons installed. I’m sorry for wasting your time, I will clean my installation and go back to you next time.

No worries.

BTW milestone release M8 is out. :slight_smile:

1 Like

I hope I’ve got it. Please see the log.
Just in case:
openhab> list -s | grep squeeze
266 x Active x 80 x 2.4.0.M8 x org.openhab.binding.squeezebox

openhab.log.4.log.xml (27.9 KB)

I don’t see anything out of the ordinary in the log. Next time it happens, include a larger section of the log file.

The last volume set and report from both players (A3 and A9) looks ok.

2018-12-14 07:43:16.940 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:e2:3a:a3 mixer volume 55
2018-12-14 07:43:17.068 [TRACE] [rnal.handler.SqueezeBoxServerHandler] - Message received: b8%3A27%3Aeb%3Ae2%3A3a%3Aa3 mixer volume 55
2018-12-14 07:43:15.733 [DEBUG] [rnal.handler.SqueezeBoxServerHandler] - Sending command: b8:27:eb:0f:fa:a9 mixer volume 90
2018-12-14 07:43:15.749 [TRACE] [rnal.handler.SqueezeBoxServerHandler] - Message received: b8%3A27%3Aeb%3A0f%3Afa%3Aa9 mixer volume 90