Jun 25 20:01:01 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:11 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:11 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:11 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:11 volumio volumio[1508]: info: VolumeController::SetAlsaVolume-
Jun 25 20:01:11 volumio volumio[1508]: info: CoreStateMachine::pushState
Jun 25 20:01:11 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jun 25 20:01:11 volumio volumio[1508]: info: CoreCommandRouter::volumioPushState
Jun 25 20:01:11 volumio volumio[1508]: info: PeppyMeterBasic ---peppymeterbasic status pause
Jun 25 20:01:11 volumio volumio[1508]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53
Jun 25 20:01:11 volumio volumio[1508]: SPOTIFY: SPOTIFY VOLUME 54
Jun 25 20:01:11 volumio volumio[1508]: SPOTIFY: VOLUMIO VOLUME 53
Jun 25 20:01:11 volumio volumio[1508]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jun 25 20:01:11 volumio sudo[6026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Jun 25 20:01:11 volumio sudo[6026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jun 25 20:01:11 volumio sudo[6026]: pam_unix(sudo:session): session closed for user root
Jun 25 20:01:11 volumio volumio[1508]: info: peppymeterbasic Daemon Stop
Jun 25 20:01:14 volumio volumio[1508]: info: CoreCommandRouter::volumioVolatilePlay
Jun 25 20:01:14 volumio volumio[1508]: ------------------------------------ BT MESSAGE: [FUNC] play
Jun 25 20:01:14 volumio volumio[1508]: ------------------------------------ BT MESSAGE: sendPlay -> calling D-Bus Play()
Jun 25 20:01:15 volumio go-librespot[1845]: time="2025-06-25T20:01:15+02:00" level=trace msg="received accesspoint ping"
Jun 25 20:01:15 volumio go-librespot[1845]: time="2025-06-25T20:01:15+02:00" level=trace msg="received accesspoint pong ack"
Jun 25 20:01:15 volumio go-librespot[1845]: time="2025-06-25T20:01:15+02:00" level=trace msg="sent dealer ping"
Jun 25 20:01:15 volumio go-librespot[1845]: time="2025-06-25T20:01:15+02:00" level=trace msg="received dealer pong"
Jun 25 20:01:20 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:20 volumio volumio[1508]: info: Preloading song: spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q
Jun 25 20:01:20 volumio volumio[1508]: info: Exploding uri spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q in service spop
Jun 25 20:01:20 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q
Jun 25 20:01:20 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q","service":"spop","name":"DANÇARINA (feat. Nicky Jam, MC Pedrinho) - Remix","artist":"PEDRO SAMPAIO","album":"DANÇARINA (feat. Nicky Jam, MC Pedrinho) [Remix]","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b27386ec217718905b9eeb9f712f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:21 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::serviceStop
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::serviceStop
Jun 25 20:01:21 volumio volumio[1508]: error: WARNING: No stop method for service [object Object]
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:21 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q
Jun 25 20:01:21 volumio volumio[1508]: info: Using cached record of: spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:21 volumio volumio[1508]: verbose: UNSET VOLATILE: Service: [object Object]
Jun 25 20:01:21 volumio volumio[1508]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth
Jun 25 20:01:21 volumio volumio[1508]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput
Jun 25 20:01:21 volumio volumio[1508]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:21 volumio volumio[1508]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled.
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::stPlaybackTimer
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::pushState
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushState
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::serviceStop
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::serviceStop
Jun 25 20:01:21 volumio volumio[1508]: info: Spotify Stop
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: SPOTIFY STOP
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: {"status":"pause","title":"","artist":"","album":"","albumart":"/albumart?web=default","trackType":"","codec":"","seek":0,"duration":0,"consume":false,"volume":53,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"bluetooth"}
Jun 25 20:01:21 volumio volumio[1508]: info: Sending Spotify command to local API: /player/pause
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::resetVolumioState
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::getcurrentVolume
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioRetrievevolume
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioStop
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:21 volumio volumio[1508]: info: [1750874481333] ControllerSpotify::clearAddPlayTrack
Jun 25 20:01:21 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:01:21 volumio volumio[1508]: info: PeppyMeterBasic ---peppymeterbasic status stop
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: SPOTIFY VOLUME 54
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jun 25 20:01:21 volumio sudo[6045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Jun 25 20:01:21 volumio sudo[6045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jun 25 20:01:21 volumio volumio[1508]: info: VolumeController:: Volume=53 Mute =false
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::pushState
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushState
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioRetrievevolume
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="resolved context of track" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio sudo[6045]: pam_unix(sudo:session): session closed for user root
Jun 25 20:01:21 volumio volumio[1508]: info: PeppyMeterBasic ---peppymeterbasic status stop
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: SPOTIFY VOLUME 54
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jun 25 20:01:21 volumio sudo[6052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Jun 25 20:01:21 volumio sudo[6052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jun 25 20:01:21 volumio volumio[1508]: info: peppymeterbasic Daemon Stop
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=trace msg="emitting websocket event: will_play"
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q","play_origin":"go-librespot"}}
Jun 25 20:01:21 volumio volumio[1508]: info: VolumeController:: Volume=53 Mute =false
Jun 25 20:01:21 volumio volumio[1508]: info: CoreStateMachine::pushState
Jun 25 20:01:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushState
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="selected format OGG_VORBIS_320 (b2aa9a9ad08384291fcd49581647ab6fc92e5dfa)" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="requested aes key for file b2aa9a9ad08384291fcd49581647ab6fc92e5dfa, gid: 5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio sudo[6052]: pam_unix(sudo:session): session closed for user root
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345"
Jun 25 20:01:21 volumio volumio[1508]: info: PeppyMeterBasic ---peppymeterbasic status stop
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: SPOTIFY VOLUME 54
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: VOLUMIO VOLUME 53
Jun 25 20:01:21 volumio volumio[1508]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jun 25 20:01:21 volumio volumio[1508]: info: peppymeterbasic Daemon Stop
Jun 25 20:01:21 volumio sudo[6056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service
Jun 25 20:01:21 volumio sudo[6056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Jun 25 20:01:21 volumio systemd[1]: systemd-timedated.service: Deactivated successfully.
Jun 25 20:01:21 volumio sudo[6056]: pam_unix(sudo:session): session closed for user root
Jun 25 20:01:21 volumio volumio[1508]: info: peppymeterbasic Daemon Stop
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="fetched first chunk of 17, total size is 8770680 bytes" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="created new output device"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1348"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames"
Jun 25 20:01:21 volumio go-librespot[1845]: time="2025-06-25T20:01:21+02:00" level=info msg="loaded track \"DANÇARINA (feat. Nicky Jam, MC Pedrinho) - Remix\" (paused: false, position: 0ms, duration: 212000ms, prefetched: false)" uri="spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q"
Jun 25 20:01:21 volumio go-librespot[1845]: go-librespot: pcm_meter.c:1220: snd_pcm_scope_s16_get_channel_buffer: Assertion `s16->buf_areas' failed.
Jun 25 20:01:21 volumio go-librespot[1844]: Aborted
Jun 25 20:01:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a
Jun 25 20:01:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jun 25 20:01:21 volumio volumio[1508]: info: Connection to go-librespot Websocket closed
Jun 25 20:01:21 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up
Jun 25 20:01:23 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:23 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:23 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:23 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:23 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:23 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:23 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:23 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:23 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:23 volumio volumio[1508]: info: [1750874483038] ControllerSpotify::clearAddPlayTrack
Jun 25 20:01:23 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:01:23 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:01:24 volumio volumio[1508]: info: Initializing connection to go-librespot Websocket
Jun 25 20:01:24 volumio volumio[1508]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:01:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Jun 25 20:01:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:01:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:01:24 volumio go-librespot[6076]: go-librespot daemon starting...
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=info msg="running go-librespot 0.2.0"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="app state loaded"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=info msg="zeroconf server listening on port 33307"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="obtained new client token: AABDqHKPegGGuP3XX4XWrxMIRGRRCm8CSi3ta5ise/HuGlYrmvhpYG15zDf0UQbQxUQ9NIjaPmT/H9aFmgHjDC6V3i4bG/641NQwwBldik8Iay4dN9aegF/tMwne1rioot6F/NzOfUbiFkS4XRSfz8RucmKV55EGb3OIsG6bLDmRBAm+uj6PmcfZ36XPhEHTHbgPQBT0FjE5gJPnrLNTlGV0eG8sxmZXDD/MsqzEGQWTlPEL1hHqMhB+Qg=="
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="completed keyexchange"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=debug msg="completed challenge"
Jun 25 20:01:24 volumio go-librespot[6077]: time="2025-06-25T20:01:24+02:00" level=info msg="authenticated AP as richard.rohn"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=info msg="authenticated Login5 as richard.rohn"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="initializing zeroconf session, username: richard.rohn"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="dealer connection opened"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=trace msg="starting accesspoint recv loop"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=trace msg="starting dealer recv loop"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=trace msg="received accesspoint ping"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="received connection id: MWFkZjk5NTctM2Y4ZC00NDAwLTk4ZmMtYzg5MDE3YmQwYTdkK2RlYWxlcit0Y3A6Ly8wYWIxNTI0NC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMTFFRTlCRkZBQjkyNjlDMENBRThBMzQwNjJEOENDNTNENUM5NkJBNDI5QjQ5NDlBMkFFREE5REI1MTYwQUYyMA=="
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=trace msg="received accesspoint pong ack"
Jun 25 20:01:25 volumio go-librespot[6077]: time="2025-06-25T20:01:25+02:00" level=debug msg="put connect state because NEW_DEVICE"
Jun 25 20:01:27 volumio volumio[1508]: info: Initializing connection to go-librespot Websocket
Jun 25 20:01:27 volumio go-librespot[6077]: time="2025-06-25T20:01:27+02:00" level=debug msg="new websocket client"
Jun 25 20:01:27 volumio volumio[1508]: info: Connection to go-librespot Websocket established
Jun 25 20:01:30 volumio volumio[1508]: info: Getting Spotify volume
Jun 25 20:01:30 volumio volumio[1508]: info: Spotify volume: 100
Jun 25 20:01:30 volumio volumio[1508]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12
Jun 25 20:01:30 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:30 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:30 volumio volumio[1508]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53
Jun 25 20:01:30 volumio volumio[1508]: SPOTIFY: SPOTIFY VOLUME 100
Jun 25 20:01:30 volumio volumio[1508]: SPOTIFY: VOLUMIO VOLUME 53
Jun 25 20:01:30 volumio volumio[1508]: SPOTIFY: DELTA VOLUME ENOUGH: true
Jun 25 20:01:30 volumio volumio[1508]: info: Setting Spotify Volume from Volumio: 53
Jun 25 20:01:30 volumio volumio[1508]: info: Removing uri spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q from favourites
Jun 25 20:01:30 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: spop , removeFromFavourites
Jun 25 20:01:30 volumio volumio[1508]: info: Error : CoreCommandRouter::executeOnPlugin: No method [removeFromFavourites] in plugin spop
Jun 25 20:01:30 volumio volumio[1508]: info: Saving Cloud item favourites
Jun 25 20:01:30 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem
Jun 25 20:01:30 volumio volumio[1508]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:5QQKWOwPjG9vcDBTQ5Hv5Q","favourite":false}
Jun 25 20:01:31 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:31 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:31 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:31 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:32 volumio volumio[1508]: SPOTIFY: SETTING SPOTIFY VOLUME 53
Jun 25 20:01:32 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/volume
Jun 25 20:01:32 volumio go-librespot[6077]: time="2025-06-25T20:01:32+02:00" level=debug msg="update volume to 34733/65535"
Jun 25 20:01:33 volumio go-librespot[6077]: time="2025-06-25T20:01:33+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Jun 25 20:01:33 volumio go-librespot[6077]: time="2025-06-25T20:01:33+02:00" level=trace msg="emitting websocket event: volume"
Jun 25 20:01:33 volumio volumio[1508]: SPOTIFY: received: {"type":"volume","data":{"value":53,"max":100}}
Jun 25 20:01:33 volumio volumio[1508]: SPOTIFY: RECEIVED SPOTIFY VOLUME 53
Jun 25 20:01:38 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Jun 25 20:01:38 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:39 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Jun 25 20:01:39 volumio volumio[1508]: info: Getting webradio selection
Jun 25 20:01:39 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:40 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:40 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:40 volumio volumio[1508]: info: Adding Item to queue: https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:40 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:40 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:40 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:40 volumio volumio[1508]: info: [1750874500392] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:40 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:40 volumio volumio[1508]: info: sendMpdCommand stop took 2 milliseconds
Jun 25 20:01:40 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:40 volumio volumio[1508]: info:
Jun 25 20:01:40 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:40 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:40 volumio volumio[1508]: info: sendMpdCommand clear took 0 milliseconds
Jun 25 20:01:40 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:01:40 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:40 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:01:41 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:41 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:45 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:45 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:45 volumio volumio[1508]: info: Adding Item to queue: https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:45 volumio volumio[1508]: info: [1750874505306] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:45 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:45 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:45 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:45 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:46 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:46 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:46 volumio volumio[1508]: info: Adding Item to queue: https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:46 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:46 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:46 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:46 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:46 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:46 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:46 volumio volumio[1508]: info: [1750874506006] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:46 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:47 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:47 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:47 volumio volumio[1508]: info: Adding Item to queue: http://stream.artsound.fm/mp3
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:47 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:47 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:47 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:47 volumio volumio[1508]: info: [1750874507183] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:47 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:48 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:48 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:48 volumio volumio[1508]: info: Adding Item to queue: https://listen-msmn.sharp-stream.com/nme1.mp3
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:48 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:48 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:48 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:48 volumio volumio[1508]: info: [1750874508996] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:48 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:49 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:49 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:49 volumio volumio[1508]: info: Adding Item to queue: https://listen-msmn.sharp-stream.com/nme1.mp3
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:49 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:49 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:49 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:49 volumio volumio[1508]: info: [1750874509720] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:49 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:50 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:50 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:50 volumio volumio[1508]: info: Adding Item to queue: https://listen-msmn.sharp-stream.com/nme1.mp3
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:50 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:50 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:50 volumio volumio[1508]: info: [1750874510395] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 5397 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 4697 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 3520 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 1707 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 983 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand stop took 308 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info:
Jun 25 20:01:50 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:01:50 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand clear took 2 milliseconds
Jun 25 20:01:50 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "http://stream.artsound.fm/mp3"
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:01:50 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 3ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:01:50 volumio volumio[1508]: info: sendMpdCommand play took 3 milliseconds
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:01:51 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:51 volumio volumio[1508]: info: Listing playlists
Jun 25 20:01:51 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:51 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:51 volumio volumio[1508]: info: Adding Item to queue: https://listen-msmn.sharp-stream.com/nme1.mp3
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:51 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:51 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:51 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:51 volumio volumio[1508]: info: [1750874511660] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:51 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:54 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Jun 25 20:01:54 volumio volumio[1508]: info: TuneIn handleBrowseUri: tunein/local
Jun 25 20:01:55 volumio go-librespot[6077]: time="2025-06-25T20:01:55+02:00" level=trace msg="sent dealer ping"
Jun 25 20:01:55 volumio go-librespot[6077]: time="2025-06-25T20:01:55+02:00" level=trace msg="received dealer pong"
Jun 25 20:01:55 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:55 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:56 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:56 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:56 volumio volumio[1508]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s298917
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:56 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:56 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:56 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:56 volumio volumio[1508]: info: [1750874516750] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:56 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:57 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:57 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:57 volumio volumio[1508]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s298917
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:57 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:57 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:57 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:57 volumio volumio[1508]: info: [1750874517544] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:57 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:58 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:58 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:58 volumio volumio[1508]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s298917
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:58 volumio volumio[1508]: info: [1750874518132] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:58 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:01:58 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:01:58 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:01:58 volumio volumio[1508]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s298917
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::play index 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:01:58 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::volumioGetVisibleSources
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jun 25 20:01:58 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Jun 25 20:01:58 volumio volumio[1508]: info: [1750874518699] ControllerWebradio::clearAddPlayTrack
Jun 25 20:01:58 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand stop
Jun 25 20:02:01 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:02:01 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:02:02 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jun 25 20:02:02 volumio volumio[1508]: info: In handleBrowseUri, curUri=spotify
Jun 25 20:02:03 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:03 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:03 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:03 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:04 volumio volumio[1508]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jun 25 20:02:04 volumio volumio[1508]: info: In handleBrowseUri, curUri=spotify/mytracks
Jun 25 20:02:04 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:04 volumio volumio[1508]: info: Preloading song: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:2A2zxpj3E9zJuFnqxYTVSx in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:6M3O3xOKfKqXYxK2XtWDcS in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2A2zxpj3E9zJuFnqxYTVSx","service":"spop","name":"Sad To Know (You're Leaving)","artist":"Gregory Isaacs","album":"Night Nurse (Expanded Edition)","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b27326f8a0f6a4abe3088c6074ad","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:3nnG7AM9QopHVPEuLX3Khk in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6M3O3xOKfKqXYxK2XtWDcS","service":"spop","name":"Viva La Siesta","artist":"Dennis Allen","album":"Viva La Siesta","type":"song","duration":366,"albumart":"https://i.scdn.co/image/ab67616d0000b2735dce0fecf927605e310c5fd8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:1Eb90nmqTrxylKFhcUzW8P in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3nnG7AM9QopHVPEuLX3Khk","service":"spop","name":"Let It Go","artist":"James Bay","album":"Chaos And The Calm","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b273066483b34a405583429b8049","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:273QnyCvJB65rScHJ1nPZb in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:5zT5cMnMKoyruPj13TQXGx in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Eb90nmqTrxylKFhcUzW8P","service":"spop","name":"(Everything I Do) I Do It For You","artist":"Bryan Adams","album":"Waking Up The Neighbours","type":"song","duration":393,"albumart":"https://i.scdn.co/image/ab67616d0000b27305a41288f037a08fb45db5e2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:2R4O7MgIrN35QXnyLKMFVl in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:273QnyCvJB65rScHJ1nPZb","service":"spop","name":"Make You Feel My Love","artist":"Adele","album":"19","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb11b9cceabfa9a40ba3f720","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:7ia5l12mCvbQTeAnG1oYpg in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5zT5cMnMKoyruPj13TQXGx","service":"spop","name":"I Found","artist":"Amber Run","album":"5AM (Expanded Edition)","type":"song","duration":273,"albumart":"https://i.scdn.co/image/ab67616d0000b27307a1897752cd38db3e9e43f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2R4O7MgIrN35QXnyLKMFVl","service":"spop","name":"Mrs.","artist":"Leon Bridges","album":"Good Thing","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b273a47ee7a49c53ccdcb38dc874","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:4W9DGGxg1mNQRpeROV30iU in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ia5l12mCvbQTeAnG1oYpg","service":"spop","name":"MY POWER","artist":"Nija","album":"The Lion King: The Gift","type":"song","duration":259,"albumart":"https://i.scdn.co/image/ab67616d0000b2734ccc03169b086af698178a99","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:04 volumio volumio[1508]: info: Exploding uri spotify:track:2P3cEaLNB0qczz4BDB7Mxc in service spop
Jun 25 20:02:04 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4W9DGGxg1mNQRpeROV30iU","service":"spop","name":"A Part of Us","artist":"Yael Naim","album":"Mon Bébé (Original Motion Picture Soundtrack)","type":"song","duration":332,"albumart":"https://i.scdn.co/image/ab67616d0000b27312f6e52390fb51e268d2b5d4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:3Ov05KIwJljawDuWbd7oKn in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2P3cEaLNB0qczz4BDB7Mxc","service":"spop","name":"Don't Stop Movin'","artist":"Livin' Joy","album":"Don’t Stop Movin’","type":"song","duration":319,"albumart":"https://i.scdn.co/image/ab67616d0000b2737d1b4387ef61788f72715186","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:3vZOFm8dqHgYaLFGV0aLkI in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3Ov05KIwJljawDuWbd7oKn","service":"spop","name":"Way of Life (with Slightly Stoopid)","artist":"Stick Figure","album":"Way of Life (with Slightly Stoopid)","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b2734f9767216ba61cffccf9b140","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:0VZwWcTjedfM5CoF9mV1yr in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3vZOFm8dqHgYaLFGV0aLkI","service":"spop","name":"Smokin' Love","artist":"Stick Figure","album":"Smokin' Love","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b2731e25e1670038e73bcbee1d66","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:4c8lGW3yXRTsk2r4WRjheh in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0VZwWcTjedfM5CoF9mV1yr","service":"spop","name":"Veto","artist":"SOHN","album":"Tremors","type":"song","duration":235,"albumart":"https://i.scdn.co/image/ab67616d0000b273aa2735c280b65f9a241ac1b6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:51rPRW8NjxZoWPPjnRGzHw in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4c8lGW3yXRTsk2r4WRjheh","service":"spop","name":"Marin","artist":"Bernard Lavilliers","album":"Carnets De Bord","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b2731805734420501ea44365a518","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:6zWU7YALeEDMcPGhKKZJhV in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:7BKLCZ1jbUBVqRi2FVlTVw in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6zWU7YALeEDMcPGhKKZJhV","service":"spop","name":"Navajo","artist":"Masego","album":"Navajo","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b27328f137f2d8bda3ddd5d045cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:51rPRW8NjxZoWPPjnRGzHw","service":"spop","name":"Tadow","artist":"Masego","album":"Lady Lady","type":"song","duration":301,"albumart":"https://i.scdn.co/image/ab67616d0000b273f1814f1b76df2fa196e4f45e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:7naxodOPmCuqK28KFRdJTR in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7BKLCZ1jbUBVqRi2FVlTVw","service":"spop","name":"Closer","artist":"The Chainsmokers","album":"Closer","type":"song","duration":244,"albumart":"https://i.scdn.co/image/ab67616d0000b273495ce6da9aeb159e94eaa453","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:6F76ic7c6au3QxG6jaso7N in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:3GBGdtSuPKI81bzrniHuF3 in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7naxodOPmCuqK28KFRdJTR","service":"spop","name":"Amar 24 / 24","artist":"Calema","album":"Yellow","type":"song","duration":363,"albumart":"https://i.scdn.co/image/ab67616d0000b2734a76ea326ab707a1bcc2d714","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:2hYlWnPvVZtQZGWfb35HPQ in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3GBGdtSuPKI81bzrniHuF3","service":"spop","name":"Wonderful Tonight","artist":"Eric Clapton","album":"Classic Eric Clapton","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b2738dd56690c6f135aa4c61a12e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:6WbADFqMvR8N5u0BvtsWQE in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6F76ic7c6au3QxG6jaso7N","service":"spop","name":"Sweet Little Angel - Live At The Regal Theater, Chicago, 1964","artist":"B.B. King","album":"Live At The Regal","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b273bf373fb956297a3c0aa3a9a0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:2dxpKzhDZXIOssN4ol4e3f in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2hYlWnPvVZtQZGWfb35HPQ","service":"spop","name":"I'm Not The Only One","artist":"Sam Smith","album":"In The Lonely Hour","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b273c1c177e193b3ebf1a16e158f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6WbADFqMvR8N5u0BvtsWQE","service":"spop","name":"Without You (feat. Sandro Cavazza)","artist":"Avicii","album":"AVĪCI (01)","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b27330800bfbfff51ddb031d9bd7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:6amvspSncnAIOur7ipRxuI in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2dxpKzhDZXIOssN4ol4e3f","service":"spop","name":"Vermelho","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":223,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:2HGd4YGkbVpSQ5rTbAiYWi in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:1UehyRYWHQxfj52XJbswIv in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2HGd4YGkbVpSQ5rTbAiYWi","service":"spop","name":"Baú","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":265,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:1seFIg83Eac87g1hmtBRjG in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:4GTNVGj8YUh9HPAiruRRfF in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6amvspSncnAIOur7ipRxuI","service":"spop","name":"Fugiu Com a Novela","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":195,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1UehyRYWHQxfj52XJbswIv","service":"spop","name":"Amado","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1seFIg83Eac87g1hmtBRjG","service":"spop","name":"Pirraça","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:75E2L06BTvq5wOX1SAFEOh in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4GTNVGj8YUh9HPAiruRRfF","service":"spop","name":"Você Vai Me Destruir","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":271,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:05 volumio volumio[1508]: info: Exploding uri spotify:track:615U5EAd24IfTmWzZGqKo7 in service spop
Jun 25 20:02:05 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:75E2L06BTvq5wOX1SAFEOh","service":"spop","name":"Absurdo","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":206,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:3xCQtuaz9MhezGUeUZLxc6 in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:615U5EAd24IfTmWzZGqKo7","service":"spop","name":"Quem Irá Nos Proteger","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":230,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:1d535PB6JLHUOl9CWSchEj in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3xCQtuaz9MhezGUeUZLxc6","service":"spop","name":"Ilegais","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:5H1TahkgMfdbQxSD2KPc2q in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1d535PB6JLHUOl9CWSchEj","service":"spop","name":"Quando um Homem Tem uma Mangueira no Quintal","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":133,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:2Y3gKvpXrE3iSi5LMzeknT in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5H1TahkgMfdbQxSD2KPc2q","service":"spop","name":"Meu Deus","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":294,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:6IvKz4Ax11LsLA0X0bPkqD in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Y3gKvpXrE3iSi5LMzeknT","service":"spop","name":"Minha Herança: Uma Flor","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:7MvWjN3BWt5BU0XEXUrkCc in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:1LR5KBD64oRzGEjQhAMNdj in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6IvKz4Ax11LsLA0X0bPkqD","service":"spop","name":"Ai, Ai, Ai...","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7MvWjN3BWt5BU0XEXUrkCc","service":"spop","name":"Ai, Ai, Ai... - DeepLick Radio Remix","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":290,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: info: Exploding uri spotify:track:1OrIF9k3A1wMADZnr4URUB in service spop
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: EXPLODING URI:spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1LR5KBD64oRzGEjQhAMNdj","service":"spop","name":"Boa Sorte / Good Luck (feat. Ben Harper)","artist":"Vanessa Da Mata","album":"Sim","type":"song","duration":235,"albumart":"https://i.scdn.co/image/ab67616d0000b273de316ae4adef2981d83b0233","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:06 volumio volumio[1508]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1OrIF9k3A1wMADZnr4URUB","service":"spop","name":"Boa Sorte","artist":"Vanessa Da Mata","album":"Hôtel Costes 11","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b273afbe092af62a6a7349b85102","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::getTrack 0
Jun 25 20:02:11 volumio volumio[1508]: info: Listing playlists
Jun 25 20:02:11 volumio volumio[1508]: info: Listing playlists
Jun 25 20:02:11 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:11 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::play index 1
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:11 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:11 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:11 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:11 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:11 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:11 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:11 volumio volumio[1508]: info: [1750874531912] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:11 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:11 volumio go-librespot[6077]: time="2025-06-25T20:02:11+02:00" level=debug msg="resolved context of track" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:11 volumio go-librespot[6077]: time="2025-06-25T20:02:11+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:11 volumio go-librespot[6077]: time="2025-06-25T20:02:11+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:11 volumio go-librespot[6077]: time="2025-06-25T20:02:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jun 25 20:02:11 volumio go-librespot[6077]: time="2025-06-25T20:02:11+02:00" level=trace msg="emitting websocket event: will_play"
Jun 25 20:02:11 volumio volumio[1508]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6M3O3xOKfKqXYxK2XtWDcS","play_origin":"go-librespot"}}
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="selected format OGG_VORBIS_320 (657679028df80b73784f13d83b8cf3de7501d2fa)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="requested aes key for file 657679028df80b73784f13d83b8cf3de7501d2fa, gid: 6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="fetched first chunk of 33, total size is 16990080 bytes" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="created new output device"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=debug msg="fetched chunk 1/32, size: 524288" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:12 volumio go-librespot[6077]: time="2025-06-25T20:02:12+02:00" level=info msg="loaded track \"Viva La Siesta\" (paused: false, position: 0ms, duration: 366792ms, prefetched: false)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:12 volumio go-librespot[6077]: go-librespot: pcm_meter.c:1220: snd_pcm_scope_s16_get_channel_buffer: Assertion `s16->buf_areas' failed.
Jun 25 20:02:12 volumio go-librespot[6076]: Aborted
Jun 25 20:02:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a
Jun 25 20:02:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jun 25 20:02:12 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up
Jun 25 20:02:12 volumio volumio[1508]: info: Connection to go-librespot Websocket closed
Jun 25 20:02:12 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Jun 25 20:02:12 volumio dbus-daemon[896]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.132' (uid=0 pid=6152 comm="timedatectl show --property=NTPSynchronized --valu")
Jun 25 20:02:12 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Jun 25 20:02:12 volumio dbus-daemon[896]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jun 25 20:02:12 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service.
Jun 25 20:02:12 volumio setdatetime-helper.sh[6151]: Time is already synchronized.
Jun 25 20:02:12 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Jun 25 20:02:12 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Jun 25 20:02:13 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:13 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:13 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:13 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:13 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::play index 1
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:13 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:13 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:13 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:13 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:13 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:13 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:13 volumio volumio[1508]: info: [1750874533288] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:13 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:13 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::play index 1
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:14 volumio volumio[1508]: info: [1750874534126] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:14 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:14 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::play index 1
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:14 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:14 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:14 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:14 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:14 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:15 volumio volumio[1508]: info: [1750874535001] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:15 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:15 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:15 volumio volumio[1508]: info: Initializing connection to go-librespot Websocket
Jun 25 20:02:15 volumio volumio[1508]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Jun 25 20:02:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:02:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:02:15 volumio go-librespot[6171]: go-librespot daemon starting...
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=info msg="running go-librespot 0.2.0"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="app state loaded"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=info msg="zeroconf server listening on port 44841"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="obtained new client token: AAB3aaprjWigOD3WQohD8mKBWntlRF4vh0TktPaiQOGW5Si0vQ3Dz8V65koiGG8JQZvAI7LtDUtxuYJk/AS0HoRu5JYHIMuvg5YXCz/vGKRpt3ix8WNf0MI05mvg37DEuC20wLYhdNoqosoqUCmnX629qjH+Pp4C6rvViUZp6TN6OuU6TYSDDsutbDdvuB5+lLLi7erYJGFtdPbaRGc0Tx1SXFSiu+o5eHJNaAxgOrcx3rgfyFGXjm30qA=="
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="completed keyexchange"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="completed challenge"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=info msg="authenticated AP as richard.rohn"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=info msg="authenticated Login5 as richard.rohn"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="initializing zeroconf session, username: richard.rohn"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="dealer connection opened"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=trace msg="starting accesspoint recv loop"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=trace msg="starting dealer recv loop"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=trace msg="received accesspoint ping"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="received connection id: NDQ2M2Y0YjQtNjc3Yi00M2RiLWE3MWQtZGE1YWRkYTlmYWY4K2RlYWxlcit0Y3A6Ly8wYWIxNTAwZS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOUY0NzZGRjYzRkNDOTY3NUFGNzEyOTMwODc3RTE3NjY2NzlDRkQ2NjU0RjAzMzA1MDY2NjBGNDE4NUM1NkJFNQ=="
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=trace msg="received accesspoint pong ack"
Jun 25 20:02:15 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:15 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:15 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:15 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::play index 1
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:15 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:15 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:15 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="put connect state because NEW_DEVICE"
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:15 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:15 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:15 volumio volumio[1508]: info: [1750874535957] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:15 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="resolved context of track" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:15 volumio go-librespot[6172]: time="2025-06-25T20:02:15+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=trace msg="emitting websocket event: will_play"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="selected format OGG_VORBIS_320 (657679028df80b73784f13d83b8cf3de7501d2fa)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="requested aes key for file 657679028df80b73784f13d83b8cf3de7501d2fa, gid: 6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="fetched first chunk of 33, total size is 16990080 bytes" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="created new output device"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames"
Jun 25 20:02:16 volumio go-librespot[6172]: time="2025-06-25T20:02:16+02:00" level=info msg="loaded track \"Viva La Siesta\" (paused: false, position: 0ms, duration: 366792ms, prefetched: false)" uri="spotify:track:6M3O3xOKfKqXYxK2XtWDcS"
Jun 25 20:02:16 volumio go-librespot[6172]: go-librespot: pcm_meter.c:1220: snd_pcm_scope_s16_get_channel_buffer: Assertion `s16->buf_areas' failed.
Jun 25 20:02:16 volumio go-librespot[6171]: Aborted
Jun 25 20:02:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a
Jun 25 20:02:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jun 25 20:02:16 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up
Jun 25 20:02:17 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:17 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:17 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:17 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:17 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:17 volumio volumio[1508]: info: CorePlayQueue::getTrack 1
Jun 25 20:02:17 volumio volumio[1508]: info: [1750874537901] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:17 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:17 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:18 volumio volumio[1508]: info: Initializing connection to go-librespot Websocket
Jun 25 20:02:18 volumio volumio[1508]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "http://stream.artsound.fm/mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand stop took 26860 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand stop took 21770 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand stop took 20976 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand stop took 20388 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand stop took 19821 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" took 1 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" took 2 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "http://stream.artsound.fm/mp3" took 2 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3" took 2 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3" took 2 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3" took 2 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand clear
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info:
Jun 25 20:02:18 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:18 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 5ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand clear took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 3 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 4 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 4 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 4 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 4 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: info: sendMpdCommand play took 4 milliseconds
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:18 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand load "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:18 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:02:18 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:02:18 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:02:18 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:02:18 volumio volumio[1508]: error: updateQueue error: null
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 3ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:18 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Jun 25 20:02:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:02:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Jun 25 20:02:19 volumio go-librespot[6182]: go-librespot daemon starting...
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=info msg="running go-librespot 0.2.0"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="app state loaded"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=info msg="zeroconf server listening on port 43119"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="obtained new client token: AAAY6Qc8PsIBYsASH8ZeajeFhioWPfudpqOC6LWf6pZ+t2LHOj10r4NdiQVBX8tvgeiIhSf35sWsp8s7VtTTQzrISMYx5C6wv3B5rDQUEjMxSBHYTLtp0sOFSR9C+RK90x8gTVPc0Pg0RXmfKsUa2We9vwwXCvN8LgSIhYOuage7oeoLj1mOs7oRvKrFmtHwJpzU3pIecetb2JWI7nh+KsUunbsU7iCQaBKutQNwvW1+b3Ck+NsteqMWow=="
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="completed keyexchange"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="completed challenge"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=info msg="authenticated AP as richard.rohn"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=info msg="authenticated Login5 as richard.rohn"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="initializing zeroconf session, username: richard.rohn"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="dealer connection opened"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=trace msg="starting accesspoint recv loop"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=trace msg="starting dealer recv loop"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=trace msg="received accesspoint ping"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="received connection id: MGU4ZDc2Y2UtYjFiNi00NmMwLWIxYTctOTYyZTBhOGM4ZjZmK2RlYWxlcit0Y3A6Ly8wYWIxNTIzOC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRjAxNzg5RUUzMThCMTBFRTdBREExRThCRTJFMUJBQUFFMjk0NkIwQTY4Q0Y1NjQ4OTA2Q0RFQzgzQ0U0NUZBMA=="
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=trace msg="received accesspoint pong ack"
Jun 25 20:02:19 volumio go-librespot[6183]: time="2025-06-25T20:02:19+02:00" level=debug msg="put connect state because NEW_DEVICE"
Jun 25 20:02:20 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3"
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioGetState
Jun 25 20:02:21 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:21 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::play index 8
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:21 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:21 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:21 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:21 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:21 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:21 volumio volumio[1508]: info: [1750874541277] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:21 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="resolved context of track" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio volumio[1508]: info: Initializing connection to go-librespot Websocket
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="new websocket client"
Jun 25 20:02:21 volumio volumio[1508]: info: Connection to go-librespot Websocket established
Jun 25 20:02:21 volumio volumio[1508]: info:
Jun 25 20:02:21 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:21 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3"
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme1.mp3" took 1249 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:21 volumio volumio[1508]: info:
Jun 25 20:02:21 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:21 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:21 volumio volumio[1508]: info:
Jun 25 20:02:21 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:21 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:21 volumio volumio[1508]: info:
Jun 25 20:02:21 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:21 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:21 volumio volumio[1508]: info:
Jun 25 20:02:21 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:21 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3" took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3" took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3" took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand add "http://serveur2.wanastream.com:25000/eliseradio.mp3" took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:21 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService mpd
Jun 25 20:02:21 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand play
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand play took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: ------------------------------ 1ms
Jun 25 20:02:21 volumio volumio[1508]: info: ------------------------------ 1ms
Jun 25 20:02:21 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:21 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand play took 2 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand play took 1 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand play took 1 milliseconds
Jun 25 20:02:21 volumio volumio[1508]: info: sendMpdCommand play took 1 milliseconds
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=trace msg="emitting websocket event: will_play"
Jun 25 20:02:21 volumio volumio[1508]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4W9DGGxg1mNQRpeROV30iU","play_origin":"go-librespot"}}
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="selected format OGG_VORBIS_320 (29fbc59c21058cad5b4dac57e42033854bee0576)" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="requested aes key for file 29fbc59c21058cad5b4dac57e42033854bee0576, gid: 4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="fetched first chunk of 28, total size is 14260648 bytes" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="created new output device"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames"
Jun 25 20:02:21 volumio go-librespot[6183]: time="2025-06-25T20:02:21+02:00" level=info msg="loaded track \"A Part of Us\" (paused: false, position: 1ms, duration: 332613ms, prefetched: false)" uri="spotify:track:4W9DGGxg1mNQRpeROV30iU"
Jun 25 20:02:21 volumio go-librespot[6183]: go-librespot: pcm_meter.c:1220: snd_pcm_scope_s16_get_channel_buffer: Assertion `s16->buf_areas' failed.
Jun 25 20:02:21 volumio go-librespot[6182]: Aborted
Jun 25 20:02:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a
Jun 25 20:02:21 volumio volumio[1508]: info: Connection to go-librespot Websocket closed
Jun 25 20:02:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jun 25 20:02:21 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up
Jun 25 20:02:22 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:22 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::play index 8
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:22 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:22 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:22 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:22 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:22 volumio volumio[1508]: info: [1750874542116] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:22 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:22 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:22 volumio volumio[1508]: info:
Jun 25 20:02:22 volumio volumio[1508]: ---------------------------- MPD announces state update: player
Jun 25 20:02:22 volumio volumio[1508]: info: ControllerMpd::getState
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand status
Jun 25 20:02:22 volumio volumio[1508]: info:
Jun 25 20:02:22 volumio volumio[1508]: ---------------------------- MPD announces system playlist update
Jun 25 20:02:22 volumio volumio[1508]: info: Ignoring MPD Status Update
Jun 25 20:02:22 volumio volumio[1508]: info:
Jun 25 20:02:22 volumio volumio[1508]: ---------------------------- MPD announces state update: player
Jun 25 20:02:22 volumio volumio[1508]: info: sendMpdCommand status took 15 milliseconds
Jun 25 20:02:22 volumio volumio[1508]: info: ControllerMpd::getState
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand status
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::parseState
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jun 25 20:02:22 volumio volumio[1508]: info: ------------------------------ 2ms
Jun 25 20:02:22 volumio volumio[1508]: info: sendMpdCommand status took 1 milliseconds
Jun 25 20:02:22 volumio volumio[1508]: info: sendMpdCommand playlistinfo took 0 milliseconds
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::parseState
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::parseTrackInfo
Jun 25 20:02:22 volumio volumio[1508]: info: ControllerMpd::pushState
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::servicePushState
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:22 volumio volumio[1508]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Jun 25 20:02:22 volumio volumio[1508]: info: ------------------------------ 18ms
Jun 25 20:02:22 volumio volumio[1508]: info: sendMpdCommand playlistinfo took 1 milliseconds
Jun 25 20:02:22 volumio volumio[1508]: verbose: ControllerMpd::parseTrackInfo
Jun 25 20:02:22 volumio volumio[1508]: info: ControllerMpd::pushState
Jun 25 20:02:22 volumio volumio[1508]: info: CoreCommandRouter::servicePushState
Jun 25 20:02:22 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:22 volumio volumio[1508]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Jun 25 20:02:22 volumio volumio[1508]: info: ------------------------------ 4ms
Jun 25 20:02:23 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:23 volumio volumio[1508]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::ClearQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::clearPlayQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:23 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2A2zxpj3E9zJuFnqxYTVSx
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6M3O3xOKfKqXYxK2XtWDcS
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:3nnG7AM9QopHVPEuLX3Khk
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1Eb90nmqTrxylKFhcUzW8P
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:273QnyCvJB65rScHJ1nPZb
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:5zT5cMnMKoyruPj13TQXGx
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2R4O7MgIrN35QXnyLKMFVl
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:7ia5l12mCvbQTeAnG1oYpg
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:4W9DGGxg1mNQRpeROV30iU
Jun 25 20:02:23 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:23 volumio volumio[1508]: info: CoreCommandRouter::volumioPlay
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::play index 8
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::addQueueItems
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::addQueueItems
Jun 25 20:02:23 volumio volumio[1508]: info: Preload queue cleared
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2P3cEaLNB0qczz4BDB7Mxc
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:3Ov05KIwJljawDuWbd7oKn
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:3vZOFm8dqHgYaLFGV0aLkI
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:0VZwWcTjedfM5CoF9mV1yr
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:4c8lGW3yXRTsk2r4WRjheh
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:51rPRW8NjxZoWPPjnRGzHw
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6zWU7YALeEDMcPGhKKZJhV
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:7BKLCZ1jbUBVqRi2FVlTVw
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:7naxodOPmCuqK28KFRdJTR
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6F76ic7c6au3QxG6jaso7N
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:3GBGdtSuPKI81bzrniHuF3
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2hYlWnPvVZtQZGWfb35HPQ
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6WbADFqMvR8N5u0BvtsWQE
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2dxpKzhDZXIOssN4ol4e3f
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6amvspSncnAIOur7ipRxuI
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2HGd4YGkbVpSQ5rTbAiYWi
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1UehyRYWHQxfj52XJbswIv
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1seFIg83Eac87g1hmtBRjG
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:4GTNVGj8YUh9HPAiruRRfF
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:75E2L06BTvq5wOX1SAFEOh
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:615U5EAd24IfTmWzZGqKo7
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:3xCQtuaz9MhezGUeUZLxc6
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1d535PB6JLHUOl9CWSchEj
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:5H1TahkgMfdbQxSD2KPc2q
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:2Y3gKvpXrE3iSi5LMzeknT
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:6IvKz4Ax11LsLA0X0bPkqD
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:7MvWjN3BWt5BU0XEXUrkCc
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1LR5KBD64oRzGEjQhAMNdj
Jun 25 20:02:23 volumio volumio[1508]: info: Adding Item to queue: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:23 volumio volumio[1508]: info: Using cached record of: spotify:track:1OrIF9k3A1wMADZnr4URUB
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::stop
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:23 volumio volumio[1508]: info: CoreCommandRouter::volumioPushQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::saveQueue
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::play index undefined
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::setConsumeUpdateService undefined
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::updateTrackBlock
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::getTrackBlock
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:23 volumio volumio[1508]: info: CoreStateMachine::startPlaybackTimer
Jun 25 20:02:23 volumio volumio[1508]: info: CorePlayQueue::getTrack 8
Jun 25 20:02:23 volumio volumio[1508]: info: [1750874543092] ControllerSpotify::clearAddPlayTrack
Jun 25 20:02:23 volumio volumio[1508]: info: Sending Spotify command with payload to local API: /player/play
Jun 25 20:02:23 volumio volumio[1508]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:24 volumio volumio[1508]: info: Getting Spotify volume
Jun 25 20:02:24 volumio volumio[1508]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jun 25 20:02:24 volumio volumio[1508]: Error: connect ECONNREFUSED 127.0.0.1:9879
Jun 25 20:02:24 volumio volumio[1508]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Jun 25 20:02:24 volumio volumio[1508]: errno: -111,
Jun 25 20:02:24 volumio volumio[1508]: code: 'ECONNREFUSED',
Jun 25 20:02:24 volumio volumio[1508]: syscall: 'connect',
Jun 25 20:02:24 volumio volumio[1508]: address: '127.0.0.1',
Jun 25 20:02:24 volumio volumio[1508]: port: 9879,
Jun 25 20:02:24 volumio volumio[1508]: response: undefined
Jun 25 20:02:24 volumio volumio[1508]: }
Jun 25 20:02:24 volumio volumio[1508]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jun 25 20:02:24 volumio sudo[6226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-25 20:01'
Jun 25 20:02:24 volumio sudo[6226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="cee9bb5b0ee50e4898478097a64b5c6c77d5a212"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="b0310d60a07948a2a8a2e8db322034758c86aad6"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Jun 21 15:01:23 UTC 2025"
VOLUMIO_VERSION="4.013"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="6df2d5f0b86e6f2c0cd4dc68c66de48c"