Jan 11 16:57:09 dachboden volumio[1285]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 11 16:57:09 dachboden volumio[1285]: info: In handleBrowseUri, curUri=spotify Jan 11 16:57:09 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:09 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:09 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:09 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:14 dachboden volumio[1285]: Searching plugin music_service/spop Jan 11 16:57:14 dachboden volumio[1285]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 11 16:57:17 dachboden go-librespot[1618]: time="2026-01-11T16:57:17+01:00" level=trace msg="sent dealer ping" Jan 11 16:57:17 dachboden go-librespot[1618]: time="2026-01-11T16:57:17+01:00" level=trace msg="received dealer pong" Jan 11 16:57:20 dachboden volumio[1285]: info: All search sources collected, pushing search results Jan 11 16:57:23 dachboden volumio[1285]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 11 16:57:23 dachboden volumio[1285]: info: In handleBrowseUri, curUri=spotify:artist:2YZyLoL8N0Wb9xBt1NhZWg Jan 11 16:57:27 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:3GCdLUSnKSMJhs4Tj6CV3s Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:2CGNAOSuO1MEFCbBRgUzjd Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:6AI3ezQ4o3HUoP6Dhudph3 Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:74tLlkN3rgVzRqQJgPfink Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:0aB0v4027ukVziUGwVGYpG Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:7KXjTSCq5nL1LoYtL7XAwS Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:2tudvzsrR56uom6smgOcSf Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:6REbwUNlppTfcnV4d4ZoZi Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:6PGoSes0D9eUDeeAafB2As Jan 11 16:57:27 dachboden volumio[1285]: info: Preloading song: spotify:track:6IZvVAP7VPPnsGX6bvgkqg Jan 11 16:57:27 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:27 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:57:47 dachboden go-librespot[1618]: time="2026-01-11T16:57:47+01:00" level=trace msg="sent dealer ping" Jan 11 16:57:47 dachboden go-librespot[1618]: time="2026-01-11T16:57:47+01:00" level=trace msg="received dealer pong" Jan 11 16:57:49 dachboden volumio[1285]: Searching plugin music_service/spop Jan 11 16:57:49 dachboden volumio[1285]: info: CoreCommandRouter::executeOnPlugin: spop , search Jan 11 16:57:50 dachboden volumio[1285]: info: All search sources collected, pushing search results Jan 11 16:58:16 dachboden go-librespot[1618]: time="2026-01-11T16:58:16+01:00" level=trace msg="received accesspoint ping" Jan 11 16:58:16 dachboden go-librespot[1618]: time="2026-01-11T16:58:16+01:00" level=trace msg="received accesspoint pong ack" Jan 11 16:58:17 dachboden go-librespot[1618]: time="2026-01-11T16:58:17+01:00" level=trace msg="sent dealer ping" Jan 11 16:58:17 dachboden go-librespot[1618]: time="2026-01-11T16:58:17+01:00" level=trace msg="received dealer pong" Jan 11 16:58:19 dachboden volumio[1285]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 11 16:58:19 dachboden volumio[1285]: info: In handleBrowseUri, curUri=spotify:playlist:4VFzrHZF5KOeppbPS5PEke Jan 11 16:58:21 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:58:21 dachboden volumio[1285]: info: Preloading song: spotify:track:5ho7VSXSmI2KM2nDjcnLyz Jan 11 16:58:21 dachboden volumio[1285]: info: Preloading song: spotify:track:1bNKBsSLpZ8vfASu45ctgA Jan 11 16:58:21 dachboden volumio[1285]: info: Preloading song: spotify:track:0nj9Bq5sHDiTxSHunhgkFb Jan 11 16:58:21 dachboden volumio[1285]: info: Preloading song: spotify:track:3goctAzym2AXmgTyER3QQ1 Jan 11 16:58:21 dachboden volumio[1285]: info: Preloading song: spotify:track:0aB0v4027ukVziUGwVGYpG Jan 11 16:58:21 dachboden volumio[1285]: info: Exploding uri spotify:track:5ho7VSXSmI2KM2nDjcnLyz in service spop Jan 11 16:58:21 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:track:5ho7VSXSmI2KM2nDjcnLyz Jan 11 16:58:21 dachboden volumio[1285]: info: Exploding uri spotify:track:1bNKBsSLpZ8vfASu45ctgA in service spop Jan 11 16:58:21 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:track:1bNKBsSLpZ8vfASu45ctgA Jan 11 16:58:21 dachboden volumio[1285]: info: Exploding uri spotify:track:0nj9Bq5sHDiTxSHunhgkFb in service spop Jan 11 16:58:21 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:track:0nj9Bq5sHDiTxSHunhgkFb Jan 11 16:58:21 dachboden volumio[1285]: info: Exploding uri spotify:track:3goctAzym2AXmgTyER3QQ1 in service spop Jan 11 16:58:21 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:track:3goctAzym2AXmgTyER3QQ1 Jan 11 16:58:21 dachboden volumio[1285]: info: Exploding uri spotify:track:0aB0v4027ukVziUGwVGYpG in service spop Jan 11 16:58:21 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:track:0aB0v4027ukVziUGwVGYpG Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ho7VSXSmI2KM2nDjcnLyz","service":"spop","name":"man at the garden","artist":"Kendrick Lamar","album":"GNX","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b273d9985092cd88bffd97653b58","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1bNKBsSLpZ8vfASu45ctgA","service":"spop","name":"Summer Days","artist":"CosmicJelly","album":"Summer Days","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b273f0cec65b3bd52ed4acdfbbcb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3goctAzym2AXmgTyER3QQ1","service":"spop","name":"One More Time","artist":"CosmicJelly","album":"One More Time","type":"song","duration":171,"albumart":"https://i.scdn.co/image/ab67616d0000b273ddc9a9b5f02d53f49a61e75b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0nj9Bq5sHDiTxSHunhgkFb","service":"spop","name":"squabble up","artist":"Kendrick Lamar","album":"GNX","type":"song","duration":157,"albumart":"https://i.scdn.co/image/ab67616d0000b273d9985092cd88bffd97653b58","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0aB0v4027ukVziUGwVGYpG","service":"spop","name":"tv off (feat. lefty gunplay)","artist":"Kendrick Lamar","album":"GNX","type":"song","duration":220,"albumart":"https://i.scdn.co/image/ab67616d0000b273d9985092cd88bffd97653b58","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 11 16:58:22 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:58:22 dachboden volumio[1285]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 11 16:58:22 dachboden volumio[1285]: info: CoreStateMachine::ClearQueue Jan 11 16:58:22 dachboden volumio[1285]: info: CoreStateMachine::stop Jan 11 16:58:22 dachboden volumio[1285]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 11 16:58:22 dachboden volumio[1285]: info: CorePlayQueue::clearPlayQueue Jan 11 16:58:22 dachboden volumio[1285]: info: CorePlayQueue::saveQueue Jan 11 16:58:22 dachboden volumio[1285]: info: CoreCommandRouter::volumioPushQueue Jan 11 16:58:22 dachboden volumio[1285]: info: CoreStateMachine::addQueueItems Jan 11 16:58:22 dachboden volumio[1285]: info: CorePlayQueue::addQueueItems Jan 11 16:58:22 dachboden volumio[1285]: info: Preload queue cleared Jan 11 16:58:22 dachboden volumio[1285]: info: Adding Item to queue: spotify:user:spotify:playlist:4VFzrHZF5KOeppbPS5PEke Jan 11 16:58:22 dachboden volumio[1285]: info: Exploding uri spotify:user:spotify:playlist:4VFzrHZF5KOeppbPS5PEke in service spop Jan 11 16:58:22 dachboden volumio[1285]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:4VFzrHZF5KOeppbPS5PEke Jan 11 16:58:23 dachboden volumio[1285]: info: CoreCommandRouter::volumioPushQueue Jan 11 16:58:23 dachboden volumio[1285]: info: CorePlayQueue::saveQueue Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::updateTrackBlock Jan 11 16:58:23 dachboden volumio[1285]: info: CorePlayQueue::getTrackBlock Jan 11 16:58:23 dachboden volumio[1285]: info: CoreCommandRouter::volumioPlay Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::play index 0 Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::stop Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::play index undefined Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 11 16:58:23 dachboden volumio[1285]: info: CorePlayQueue::getTrack 0 Jan 11 16:58:23 dachboden volumio[1285]: info: CoreStateMachine::startPlaybackTimer Jan 11 16:58:23 dachboden volumio[1285]: info: CorePlayQueue::getTrack 0 Jan 11 16:58:23 dachboden volumio[1285]: info: [1768147103262] ControllerSpotify::clearAddPlayTrack Jan 11 16:58:23 dachboden volumio[1285]: info: Sending Spotify command with payload to local API: /player/play Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="resolved context of track" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=trace msg="emitting websocket event: will_play" Jan 11 16:58:25 dachboden volumio[1285]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:5ho7VSXSmI2KM2nDjcnLyz","uri":"spotify:track:5ho7VSXSmI2KM2nDjcnLyz","play_origin":"go-librespot"}} Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="selected format OGG_VORBIS_320 (5ad4eb01285d346a20c848138e6f9f926ae21c17)" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="requested aes key for file 5ad4eb01285d346a20c848138e6f9f926ae21c17, gid: 5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1358" Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1124" Jan 11 16:58:25 dachboden systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 11 16:58:25 dachboden go-librespot[1618]: time="2026-01-11T16:58:25+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:27 dachboden volumio[1285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 16:58:27 dachboden volumio[1285]: TypeError: Cannot read properties of null (reading 'slice') Jan 11 16:58:27 dachboden volumio[1285]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Jan 11 16:58:27 dachboden volumio[1285]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Jan 11 16:58:27 dachboden volumio[1285]: at Object.onceWrapper (node:events:629:26) Jan 11 16:58:27 dachboden volumio[1285]: at ClientRequest.emit (node:events:514:28) Jan 11 16:58:27 dachboden volumio[1285]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Jan 11 16:58:27 dachboden volumio[1285]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Jan 11 16:58:27 dachboden volumio[1285]: at TLSSocket.socketOnData (node:_http_client:535:22) Jan 11 16:58:27 dachboden volumio[1285]: at TLSSocket.emit (node:events:514:28) Jan 11 16:58:27 dachboden volumio[1285]: at addChunk (node:internal/streams/readable:343:12) Jan 11 16:58:27 dachboden volumio[1285]: at readableAddChunk (node:internal/streams/readable:316:9) Jan 11 16:58:27 dachboden volumio[1285]: at Readable.push (node:internal/streams/readable:253:10) Jan 11 16:58:27 dachboden volumio[1285]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Jan 11 16:58:27 dachboden volumio[1285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 16:58:28 dachboden go-librespot[1618]: time="2026-01-11T16:58:28+01:00" level=debug msg="fetched first chunk of 19, total size is 9872337 bytes" uri="spotify:track:5ho7VSXSmI2KM2nDjcnLyz" Jan 11 16:58:28 dachboden go-librespot[1618]: time="2026-01-11T16:58:28+01:00" level=debug msg="created new output device" Jan 11 16:58:28 dachboden go-librespot[1618]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for BossDAC Jan 11 16:58:28 dachboden go-librespot[1618]: time="2026-01-11T16:58:28+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:5ho7VSXSmI2KM2nDjcnLyz: ALSA error at snd_pcm_open: No such device" Jan 11 16:58:28 dachboden sudo[2807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 16:57' Jan 11 16:58:28 dachboden sudo[2807]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"