Showing data for wrong song when playing from queue

[oisteink]

Sometimes (usually on the 2nd song of a queue) volumio will show the 3rd song as the one it's playing. This will be reflected in both the playing part and the queue. The 2nd song name show, then change after about 4 seconds to the 3rd song. Happens both on local songs and Tidal (this is all I use).

[volumio]

Are you using plugins? Which ones

[oisteink]

Only one - my own. It does noting except for logging state change. It loggs state and song info. I can upload code later if you want. I also have pydPiper running in a Docker container, but the service was turned off most of the times I noticed it.

[xipmix]

Possibly related to #1866

[oisteink]

What I did to spot it: I made a new plugin of user_interface type, implemented a handler for pushState that writes to log if state != undefined, and it's different from the previous state (if any) based on status, title, artist and album, then stores that state in a variable called previousState

This is all it implements for now - my plan is to make a plugin that shows info on lcd display without the need of pydpiper.

if this is an issue with my code or not i don't know, I know very little about js and node.

I refresh and restart volumio by these two commands $volumio plugin refresh $service volumio restart

and then filter out my lines from the log by this command $ tail -f /var/log/volumio.log | grep --line-buffered statechangelog

then I start play, pause, next, play, next, etc. I also seek towards 90% of the song to let it time out. Purely to see if I catch the state.

I managed to recreate just now by doing this. I started playing an album from my nas, pressed next after a few seconds, then seeked to about 90% and let it run to next song. state and ui skipped 2 songs ahead.

Attached the plugin statechangelog.zip

[oisteink]

Add log of this. It's just part of my log at it's very long. The issue showed to me (i only watch my output) at 2020-01-30T21:53:32.381Z

statechange-error.log

[fominator]

I can confirm this bug. I notice it periodicaly. It has nothing to do with plugins or smth. Please fix this VERY OLD BUG FINALLY.

[volumio]

@fominator it will be really helpful if you could also share a log when the issue occurs. This is a very hard to trace bug, so having logs is fundamental to trace it down

[emalizia]

I've just observed this bug too. Unfortunately, I do not know what the steps are to make it happen again. I was listening an album with quite long tracks (between 8 and 9 minutes) and I left the browser visualising a tab different from the volumio player. When I got back to the tab with the volumio player interface, the wrong information regarding the current track (and time) were shown.

Some information on the set up:

• OS version: Volumio 2.917
• Hardware running Volumio: Allo DigiOne Player (RPi 3B+ with Allo DigiOne hat)
• Music source: Shared Windows folder on NAS
• Music format: FLAC files