Stuttering playback via Spotify Connect

Volumio Development Bug reports
, , ,
1

I’ve downloaded the Spotify Connect plugin and would like to be able to adjust the volume in the Spotify app, however, when I toggle Volume options on in the Volumio interface (Volume Options -> Mixer Type: “software”) to allow me to do so, I get stuttering playback via Spotify Connect. Tracks skip/stutter every 1-2 min, sometimes more frequently.

I’ve tried to adjust the audio buffer size and buffer before play parameters, but this does not affect the skipping/stuttering. If I toggle the Volume Options -> Mixer Type to “None”, the problem goes away.

Volumio Version: 2.843
Orchard Audio PecanPi streamer/DAC

The streamer is connected via ethernet with 75 mbps connection speed. The problem does not occur when playing Spotify within the Volumio app.

Any suggestions?

2

The PecanPi DAC uses the RPI-DAC overlay.

3

I had another customer with Spotify issue here:

Wonder if the two are related?

4

I’d reckon because the inbuilt other spotify doesn’t hook into the mixer. My hunch is that the vls daemon isn’t getting the right parameters for the mixer resulting in your issues. Could you check/share logs?

W.t.r the buffer parameters, those IIRC are only for mpd.
Can you check the hw_params of the card while it’s playing (and stuttering) and compare it to when you set the mixer to None?

5

No way to tell without logs :wink:

6

Please provide very clear instructions on how to get the logs.

7

Here’s a log including the switch from Volume Control “none” to “software.” I couldn’t find hw_params.

Starting Live Log…
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
process exited with code null[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: “No such device” }
info: VolumeController::SetAlsaVolume100
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
info: Killing previous LiveLog session
info: Live Log process terminated: null
info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object]
info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: Restoring Previous Volume level: 100 false true
info: VolumeController::SetAlsaVolume100
info: Enable softmixer device for audio device number 2
info: Enable softmixer device for audio device number 2
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
xcb_connection_has_error() returned true
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_rpi_dac Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5
info: Output device has changed, restarting MPD
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
info: Output device has changed, restarting Shairport Sync
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Music Player Daemon…
xcb_connection_has_error() returned true
info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
xcb_connection_has_error() returned true
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: Volume configurations have been set
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
[SpotifyConnect] <> or Mixer found, using softvol
xcb_connection_has_error() returned true
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5
info: CoreCommandRouter::getUIConfigOnPlugin
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
Starting Music Player Daemon…
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
info: MPD Permissions set
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: Asound.conf file written
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
xcb_connection_has_error() returned true
Started Music Player Daemon.
pam_unix(sudo:session): session closed for user root
xcb_connection_has_error() returned true
Playing WAVE ‘/volumio/app/silence.wav’ : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
xcb_connection_has_error() returned true
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: Output device has changed, restarting MPD
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
info: Output device has changed, restarting Shairport Sync
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Music Player Daemon…
xcb_connection_has_error() returned true
info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
xcb_connection_has_error() returned true
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
xcb_connection_has_error() returned true
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5
Starting Music Player Daemon…
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
xcb_connection_has_error() returned true
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
info: Getting Alsa Cards List without I2S DAC
xcb_connection_has_error() returned true
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
xcb_connection_has_error() returned true
xcb_connection_has_error() returned true
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
error: Upnp client error: Error: This socket has been ended by the other party
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
error: Cannot set ALSA Volume: Error: Alsa Mixer Error: xcb_connection_has_error() returned true
amixer: Unable to find simple control ‘’,0
info: MPD Permissions set
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: Starting Shairport Sync
[SpotifyConnect] Restarting Vollibrespot Daemon
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
[SpotifyConnect] Restarting Vollibrespot Daemon
pam_unix(sudo:session): session opened for user root by (uid=0)
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
Stopping Shairport Sync - AirPlay Audio Receiver…
Starting Shairport Sync - AirPlay Audio Receiver…
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session opened for user root by (uid=0)
output: No ‘AudioOutput’ defined in config file
output: Attempt to detect audio output device
output: Attempting to detect a alsa audio device
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
------------------------------------ BT MESSAGE: BT STATUS: running
pam_unix(sudo:session): session opened for user root by (uid=0)
output: Successfully detected a alsa audio device
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
Started Music Player Daemon.
BT PLUGIN MESSAGE: STATE:undefined
pam_unix(sudo:session): session closed for user root
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Stopping Volspotconnect2 Daemon…
Starting Volspotconnect2 Daemon…
Started Volspotconnect2 Daemon.
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
pam_unix(sudo:session): session closed for user root
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Stopping Volspotconnect2 Daemon…
Starting Volspotconnect2 Daemon…
Started Volspotconnect2 Daemon.
info: Shairport-Sync Started
[SpotifyConnect] Restarting Vollibrespot Daemon
pam_unix(sudo:session): session closed for user root
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) – Built On 2020-10-07
Reading Config from “volspotify.toml”
info: Starting Shairport Sync
[Vollibrespot] : Using Alsa backend with device: softvolume
[SpotifyConnect] Restarting Vollibrespot Daemon
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
pam_unix(sudo:session): session opened for user root by (uid=0)
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Stopping Volspotconnect2 Daemon…
Starting Volspotconnect2 Daemon…
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) – Built On 2020-10-07
Reading Config from “volspotify.toml”
[Vollibrespot] : Using Alsa backend with device: softvolume
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
pam_unix(sudo:session): session opened for user root by (uid=0)
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Stopping Shairport Sync - AirPlay Audio Receiver…
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
------------------------------------ BT MESSAGE: BT STATUS: waiting
Starting Shairport Sync - AirPlay Audio Receiver…
Started Shairport Sync - AirPlay Audio Receiver.
BT PLUGIN MESSAGE: Playing: false
pam_unix(sudo:session): session opened for user root by (uid=0)
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
error: updateQueue error: null
pam_unix(sudo:session): session closed for user root
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: “No such device” }
Stopping Volspotconnect2 Daemon…
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Starting Volspotconnect2 Daemon…
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
[SpotifyConnect] Vollibrespot Daemon service restarted!
[SpotifyConnect] Vollibrespot Daemon service restarted!
[SpotifyConnect] Vollibrespot Daemon service restarted!
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) – Built On 2020-10-07
Reading Config from “volspotify.toml”
[Vollibrespot] : Using Alsa backend with device: softvolume
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
info: Shairport-Sync Started
error: updateQueue error: null
[SpotifyConnect] Vollibrespot Daemon service restarted!
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: “No such device” }
info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Music Player Daemon…
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Starting Music Player Daemon…
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: undefined
BT PLUGIN MESSAGE: STATE:undefined
Started Music Player Daemon.
pam_unix(sudo:session): session closed for user root
error: updateQueue error: null
info: VolumeController::SetAlsaVolume100
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: VolumeController:: Setting startup Volume 100
info: VolumeController::SetAlsaVolume100
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Connecting to AP “guc3-accesspoint-b-kq86.ap.spotify.com:443”
[Vollibrespot] : Authenticated as “redpatokasea” !
[Vollibrespot] : Setting up new mixer: card:hw:2 mixer:SoftMaster index:0
[Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
[Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(0)[dB]) – max: 99 (MilliBel(0)[dB]) HW: false
[Vollibrespot] : Using Alsa linear volume
[Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
[Vollibrespot] : Using alsa sink
[Vollibrespot] : Country: “US”
[Vollibrespot] : Metadata pipe established
[Vollibrespot] : Event: Volume { volume_to_mixer: 65535 }
[SpotifyConnect] 100
[SpotifyConnect] Volume: Spotify:100 Volumio: 100
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Fetching autoplay context uri
[SpotifyConnect] A connect session has begun
[Vollibrespot] : Event: SessionActive { became_active_at: 1602690998535 }
[Vollibrespot] : SessionActive!
[Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 84920193351677668953104237875269126260, audio_type: Track } }
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 84920193351677668953104237875269126260, audio_type: Track } }
[SpotifyConnect] Device palyback is active!
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: mpd
[SpotifyConnect] Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: mpd
[SpotifyConnect] Setting Volatile state to Volspotconnect2
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Autoplay uri resolved to <“spotify:station:user:redpatokasea:playlist:0fc3QTjYCM3hZP1DGS2D6k”>
[Vollibrespot] : Resolving uri “spotify:station:user:redpatokasea:playlist:0fc3QTjYCM3hZP1DGS2D6k”
[Vollibrespot] : Event: GotToken { token: Token { access_token: “BQB5RZr020RFc_ardXbpXgpt1cBYK7zSCmS3m56P3sNj7rDCFW7bg1L35nXfN0FleRWSyKRETnNORifvBUNGecCL7f2n9e9pZhAT5kKZczo5v-hUmRSykHDfaq_YduEG0trsVLpDP5Ebp6q_SfpbBaeZn-8ipymrfJYCtmVk”, expires_in: 3600, token_type: “Bearer”, scope: [“streaming”, “user-read-playback-state”, “user-modify-playback-state”, “user-read-currently-playing”, “user-read-private”] } }
[SpotifyConnect] BQB5RZr020RFc_ardXbpXgpt1cBYK7zSCmS3m56P3sNj7rDCFW7bg1L35nXfN0FleRWSyKRETnNORifvBUNGecCL7f2n9e9pZhAT5kKZczo5v-hUmRSykHDfaq_YduEG0trsVLpDP5Ebp6q_SfpbBaeZn-8ipymrfJYCtmVk
[Vollibrespot] : Loading with Spotify URI
[SpotifyConnect] Setting VLS device_id: c6e56cf6b68c07041768b06e2f29a439e7724b0e
[Vollibrespot] : Reducing normalisation factor to prevent clipping. Please add negative pregain to avoid.
[Vollibrespot] : Resolved 50 tracks from <“spotify:user:redpatokasea:playlist:0fc3QTjYCM3hZP1DGS2D6k”>
[Vollibrespot] : (354666 ms) loaded
[Vollibrespot] : Event: SinkActive
[SpotifyConnect] Sink acquired
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Loading with Spotify URI
[Vollibrespot] : Reducing normalisation factor to prevent clipping. Please add negative pregain to avoid.
[Vollibrespot] : (404160 ms) loaded
[Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 84920193351677668953104237875269126260, audio_type: Track }, position_ms: 350600 }
[SpotifyConnect] pause
[SpotifyConnect] Young And Foolish
[SpotifyConnect] Not pushing metadata: { active: true, isStopping: true }
[Vollibrespot] : Event: SinkInactive
[SpotifyConnect] Sink released
[SpotifyConnect] Not pushing Pause { active: true, isStopping: true}
[SpotifyConnect] ResolvedStop in e[31m 680s 745.04ms e[39m
[Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 84920193351677668953104237875269126260, audio_type: Track } }
[SpotifyConnect] Device palyback is inactive
[SpotifyConnect] Device is paused

8
9

Looks like an issue with the mixer interface - shouldn’t it be looking for the SoftMaster PCM. Either way, does this DAC have a hardware mixer? If so what are the correct ALSA parameters (mixer name, device, index) to use it?

Also these repeating lines from pulse also don’t look good.

xcb_connection_has_error() returned true

Which also raises the question, why are you using pulse and not ALSA?

For the hw_params you could try and replace card0 with your actual card (2 maybe?)…

cat /proc/asound/card0/pcm0p/sub0/hw_params
10

It uses the RPI-DAC overlay. There is no hardware mixer.

11

@jhartmann Can you run some more tests via ssh to debug this?

# Stop Volumio 
volumio vstop
# Restart the VLS daemon and tail logs
systemctl restart volspotconnect2 && journalctl -f

Please share logs and let me know if you still encounter the same symptoms…

12

Yes. Can you give me instructions on how to run tests via ssh?

13

This should get you started? :slight_smile:

14

You guys should really make the SSH terminal available on the dev page. 99% of people have no idea what SSH is. Or at least a way to issue the commands and see the responses on the dev page.

15

I actually started implementing something along those lines, to have a way to quickly launch a debug session for this plugin. But the UI modals didn’t support what I had in mind, so instead there a more simpler “LiveLog” feature on the /dev page.

I don’t however think it’s a smart idea to have an unsecured webpage be able to issue arbitrary commands on the device as a privileged user.

Either way, what I requested @jhartmann to do was to stop Volumio, to isolate and check if the issue is with the daemon on the interaction with Volumio. So no way to do that without accessing the console.

16

@jhartmann take a look at the following link, that should give you all directions you need to connect via SSH:

17

Hi,
has there ever been anymore progress made on this problem? I am experiencing the same issue when using Spotify Connect and the Software mixer.

I just set up Volumio 2.861 with a RPi3 and a Hifiberry+ Light DAC and I am using the Hifiberry DAC Interface.

18

@rince could you share logs?

19

Yes, of course.
Here is the log once I activate the Software mixer

Starting Live Log...
info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioGetQueue
info: CoreStateMachine::getQueue
info: CorePlayQueue::getQueue
info: CoreCommandRouter::executeOnPlugin: system , getHwuuid
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
info: CoreCommandRouter::getUIConfigOnPlugin
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
info: Getting Alsa Cards List without I2S DAC
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object]
info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: Restoring Previous Volume level: 0 false true
info: VolumeController::SetAlsaVolume100
info: Enable softmixer device for audio device number 2
info: Enable softmixer device for audio device number 2
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: Hifiberry DAC Mixer:  Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10
info: Output device has changed, restarting MPD
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
info: Output device has changed, restarting Shairport Sync
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
pam_unix(sudo:session): session opened for user root by (uid=0)
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Music Player Daemon...
info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
[SpotifyConnect] Relinquishing Volumio State
UNSET VOLATILE
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
[SpotifyConnect] <> or  Mixer found, using softvol
info: Volume configurations have been set
[SpotifyConnect] Relinquishing Volumio State
UNSET VOLATILE
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
[SpotifyConnect] <> or  Mixer found, using softvol
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer:  Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10
info: CoreCommandRouter::getUIConfigOnPlugin
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::resetVolumioState
info: CoreStateMachine::getcurrentVolume
info: CoreCommandRouter::volumioRetrievevolume
info: CoreStateMachine::resetVolumioState
info: CoreStateMachine::getcurrentVolume
info: CoreCommandRouter::volumioRetrievevolume
Starting Music Player Daemon...
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreCommandRouter::volumioRetrievevolume
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: MPD Permissions set
error: Upnp client error: Error: This socket has been ended by the other party
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreCommandRouter::volumioRetrievevolume
info: Asound.conf file written
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: Output device has changed, restarting MPD
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
info: Output device has changed, restarting Shairport Sync
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
Stopping Music Player Daemon...
info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::volumioUpdateVolumeSettings
info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
info: Getting Alsa Cards List without I2S DAC
info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Starting Music Player Daemon...
error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0
info: MPD Permissions set
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: Starting Shairport Sync
[SpotifyConnect] Restarting Vollibrespot Daemon
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
pam_unix(sudo:session): session opened for user root by (uid=0)
[SpotifyConnect] Restarting Vollibrespot Daemon
Stopping Shairport Sync - AirPlay Audio Receiver...
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
Starting Shairport Sync - AirPlay Audio Receiver...
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
pam_unix(sudo:session): session opened for user root by (uid=0)
[SpotifyConnect] Restarting Vollibrespot Daemon
[SpotifyConnect] Restarting Vollibrespot Daemon
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Volspotconnect2 Daemon...
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
info: Starting Shairport Sync
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Volspotconnect2 Daemon...
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: softvolume
info: Shairport-Sync Started
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
Stopping Volspotconnect2 Daemon...
pam_unix(sudo:session): session opened for user root by (uid=0)
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: softvolume
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Stopping Volspotconnect2 Daemon...
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
[SpotifyConnect] Vollibrespot Daemon service restarted!
pam_unix(sudo:session): session closed for user root
[SpotifyConnect] Vollibrespot Daemon service restarted!
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: softvolume
pam_unix(sudo:session): session opened for user root by (uid=0)
[SpotifyConnect] Vollibrespot Daemon service restarted!
Stopping Shairport Sync - AirPlay Audio Receiver...
[SpotifyConnect] Vollibrespot Daemon service restarted!
Starting Shairport Sync - AirPlay Audio Receiver...
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
info: Shairport-Sync Started
info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Music Player Daemon...
Starting Music Player Daemon...
info: VolumeController::SetAlsaVolume0
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Started Music Player Daemon.
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session closed for user root
error: MPD error: false == true
error: MPD error: false == true
error: updateQueue error: null
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
error: updateQueue error: null
error: updateQueue error: null

Which logs are you looking for in particular?

20

I also did some live logging while playing music from Spotify. It appears the some buffer underrun occurs which results in the stuttering.

Is this helpinng @ashthespy?

Starting Live Log...
info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
info: CoreCommandRouter::volumioGetState
info: CoreCommandRouter::volumioGetQueue
info: CoreStateMachine::getQueue
info: CorePlayQueue::getQueue
info: CoreCommandRouter::executeOnPlugin: system , getHwuuid
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
[Vollibrespot] : Loading  with Spotify URI 
[Vollibrespot] :  (161062 ms) loaded
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
pam_unix(sudo:session): session opened for user root by (uid=0)
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
pam_unix(sudo:session): session closed for user root
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
info: CoreCommandRouter::volumioGetState
info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
info: CoreCommandRouter::volumioGetVisibleSources
info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
info: Listing playlists
info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
[Vollibrespot] : Event: Next { track_id: SpotifyId { id: 56997054916516033435083919883111801149, audio_type: Track } }
[Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 46285488299216923936756296352788564820, audio_type: Track }, track_id: SpotifyId { id: 56997054916516033435083919883111801149, audio_type: Track } }
[SpotifyConnect]  i'm gonna tell my therapist on you
[SpotifyConnect] Pushing metadata
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Loading  with Spotify URI 
[Vollibrespot] :  (169000 ms) loaded
ALSA lib pcm.c:8306:(snd_pcm_recover) underrun occurred
ALSA lib pcm.c:8306:(snd_pcm_recover) underrun occurred
[Vollibrespot] : Event: Next { track_id: SpotifyId { id: 274420266519309217704190408551723116599, audio_type: Track } }
[Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 56997054916516033435083919883111801149, audio_type: Track }, track_id: SpotifyId { id: 274420266519309217704190408551723116599, audio_type: Track } }
[SpotifyConnect]  On Thin Ice
[SpotifyConnect] Pushing metadata
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
ALSA lib pcm.c:8306:(snd_pcm_recover) underrun occurred