Aug 29 23:35:07 basement-music systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 29 23:35:08 basement-music volumio[9346]: Searching plugin music_service/spop Aug 29 23:35:08 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , search Aug 29 23:35:08 basement-music volumio[9346]: info: All search sources collected, pushing search results Aug 29 23:35:09 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 23:35:09 basement-music volumio[9346]: info: In handleBrowseUri, curUri=spotify:artist:6ZLTlhejhndI4Rh53vYhrY Aug 29 23:35:10 basement-music systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 29 23:35:10 basement-music systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 29 23:35:10 basement-music systemd[1]: setdatetime-helper.service: Consumed 1.822s CPU time. Aug 29 23:35:11 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:11 basement-music volumio[9346]: info: Preloading song: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:11 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:11 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:11 basement-music volumio[9346]: info: No valid Plugin REST Endpoint Aug 29 23:35:11 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1467. Aug 29 23:35:11 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:11 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:11 basement-music upmpdcli[10071]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:35:11 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:35:11 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:35:13 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:13 basement-music volumio[9346]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 23:35:13 basement-music volumio[9346]: info: CoreStateMachine::ClearQueue Aug 29 23:35:13 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:13 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:13 basement-music volumio[9346]: info: CorePlayQueue::clearPlayQueue Aug 29 23:35:13 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:13 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:13 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:13 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:13 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:13 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:13 basement-music volumio[9346]: info: Exploding uri spotify:track:7ACxUo21jtTHzy7ZEV56vU in service spop Aug 29 23:35:13 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7ACxUo21jtTHzy7ZEV56vU","service":"spop","name":"Crazy Train","artist":"Ozzy Osbourne","album":"Blizzard Of Ozz (40th Anniversary Expanded Edition)","type":"song","duration":293,"albumart":"https://i.scdn.co/image/ab67616d0000b2734936b5b7caeb7524e50fd8cb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:14 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::play index 0 Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:14 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:7w6PJe5KBPyvuRYxFkPssC in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:0S3gpZzlT9Hb7CCSV2owX7 in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:2ov8L95QD25TLpZAZPYWXL in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:78PKCefXwDLbl4FVO1Pjzh in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:5axOkQnmQmwtjr4bv1Xt7i in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:2E7W1X4maFFcjHrVrFA7Vs in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:31dqpLUModJWNbxrXu6TWd in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:4nvYDy427VvA1TcEkdgZII in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:14 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:14 basement-music volumio[9346]: info: Exploding uri spotify:track:43thLwzSasUUZEYjYPeJh3 in service spop Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: EXPLODING URI:spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::getTrack 0 Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::getTrack 0 Aug 29 23:35:14 basement-music volumio[9346]: info: [1788060914203] ControllerSpotify::clearAddPlayTrack Aug 29 23:35:14 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ov8L95QD25TLpZAZPYWXL","service":"spop","name":"Mr. Crowley","artist":"Ozzy Osbourne","album":"Blizzard Of Ozz (40th Anniversary Expanded Edition)","type":"song","duration":302,"albumart":"https://i.scdn.co/image/ab67616d0000b2734936b5b7caeb7524e50fd8cb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5axOkQnmQmwtjr4bv1Xt7i","service":"spop","name":"I Don't Wanna Stop","artist":"Ozzy Osbourne","album":"Black Rain (Expanded Edition)","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b273c48ac94a47b4948070b49f29","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:78PKCefXwDLbl4FVO1Pjzh","service":"spop","name":"Dreamer","artist":"Ozzy Osbourne","album":"Down To Earth","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b2736ab3121cb80e3d8da28f5b77","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2E7W1X4maFFcjHrVrFA7Vs","service":"spop","name":"Bark at the Moon","artist":"Ozzy Osbourne","album":"Bark At The Moon (Expanded Edition)","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b273feeaf9a5c2beb414fb2b7090","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:31dqpLUModJWNbxrXu6TWd","service":"spop","name":"Shot in the Dark","artist":"Ozzy Osbourne","album":"The Ultimate Sin","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273ca110425c6233c263beb0a4f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0S3gpZzlT9Hb7CCSV2owX7","service":"spop","name":"Mama, I'm Coming Home","artist":"Ozzy Osbourne","album":"No More Tears (Expanded Edition)","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b273509342e69eb341df70e5c2e3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7w6PJe5KBPyvuRYxFkPssC","service":"spop","name":"No More Tears","artist":"Ozzy Osbourne","album":"No More Tears (Expanded Edition)","type":"song","duration":444,"albumart":"https://i.scdn.co/image/ab67616d0000b273509342e69eb341df70e5c2e3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4nvYDy427VvA1TcEkdgZII","service":"spop","name":"Hellraiser","artist":"Ozzy Osbourne","album":"No More Tears (Expanded Edition)","type":"song","duration":292,"albumart":"https://i.scdn.co/image/ab67616d0000b273509342e69eb341df70e5c2e3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:43thLwzSasUUZEYjYPeJh3","service":"spop","name":"Close My Eyes Forever","artist":"Lita Ford","album":"Lita","type":"song","duration":283,"albumart":"https://i.scdn.co/image/ab67616d0000b2732dbf0cc843a4a0fe8c8f5482","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Aug 29 23:35:14 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:14 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:14 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:19 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:19 basement-music volumio[9346]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::ClearQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::clearPlayQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:19 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:19 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:19 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::play index 1 Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:19 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:19 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:19 basement-music volumio[9346]: info: Using cached record of: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:19 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:19 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:35:19 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:19 basement-music volumio[9346]: info: [1788060919341] ControllerSpotify::clearAddPlayTrack Aug 29 23:35:19 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:35:21 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::ClearQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::clearPlayQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:21 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:7ACxUo21jtTHzy7ZEV56vU Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:7w6PJe5KBPyvuRYxFkPssC Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::play index 1 Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::addQueueItems Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::addQueueItems Aug 29 23:35:21 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:0S3gpZzlT9Hb7CCSV2owX7 Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:2ov8L95QD25TLpZAZPYWXL Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:78PKCefXwDLbl4FVO1Pjzh Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:5axOkQnmQmwtjr4bv1Xt7i Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:2E7W1X4maFFcjHrVrFA7Vs Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:31dqpLUModJWNbxrXu6TWd Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:4nvYDy427VvA1TcEkdgZII Aug 29 23:35:21 basement-music volumio[9346]: info: Adding Item to queue: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:21 basement-music volumio[9346]: info: Using cached record of: spotify:track:43thLwzSasUUZEYjYPeJh3 Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::stop Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::saveQueue Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::updateTrackBlock Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrackBlock Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:21 basement-music volumio[9346]: info: [1788060921193] ControllerSpotify::clearAddPlayTrack Aug 29 23:35:21 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:35:21 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:21 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:35:21 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:21 basement-music volumio[9346]: info: [1788060921910] ControllerSpotify::clearAddPlayTrack Aug 29 23:35:21 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:35:22 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:35:22 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:35:22 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:35:22 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:22 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:35:22 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:22 basement-music volumio[9346]: info: [1788060922335] ControllerSpotify::clearAddPlayTrack Aug 29 23:35:22 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.826-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=114.555068ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.839-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.860-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=20.538617ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.872-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=31.517167ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.874-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=33.693461ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.904-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://securetoken.googleapis.com duration=64.117195ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.905-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=65.405003ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.906-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://functions.volumio.cloud duration=66.383384ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.908-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://functions.volumio.cloud duration=68.700563ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.947-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=http://pushupdates.volumio.org duration=107.262546ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.971-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://database.volumio.cloud duration=130.640944ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.971-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://google.com duration=132.227188ms Aug 29 23:35:25 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:25.971-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=https://www.googleapis.com duration=132.024636ms Aug 29 23:35:26 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:26.129-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=http://plugins.volumio.org duration=289.435996ms Aug 29 23:35:26 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:26.184-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" latency=102.321094ms timeout=10s endpoint=http://cddb.volumio.org duration=344.71807ms Aug 29 23:35:26 basement-music sudo[10089]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 23:35:26 basement-music sudo[10089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:26 basement-music sudo[10089]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:26 basement-music sudo[10091]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 23:35:26 basement-music sudo[10091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:26 basement-music sudo[10091]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:26 basement-music volumio[9346]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.148 UA: Mozilla/5.0 (Linux; Android 16; SM-S947U Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 23:35:26 basement-music sudo[10095]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 23:35:26 basement-music sudo[10095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:26 basement-music sudo[10095]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:26 basement-music sudo[10097]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 23:35:26 basement-music sudo[10097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:26 basement-music sudo[10097]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:26 basement-music volumio[9346]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.148 UA: Mozilla/5.0 (Linux; Android 16; SM-S947U Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:26 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetQueue Aug 29 23:35:26 basement-music volumio[9346]: info: CoreStateMachine::getQueue Aug 29 23:35:26 basement-music volumio[9346]: info: CorePlayQueue::getQueue Aug 29 23:35:26 basement-music volumio[9346]: info: Listing playlists Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 23:35:26 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:35:26 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:26 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:26 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 23:35:26 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1468. Aug 29 23:35:26 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:26 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 23:35:26 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:26 basement-music upmpdcli[10100]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:35:26 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:35:26 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:35:28 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:35:28 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:28 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:28 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:35:29 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:35:29 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:35:29 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:35:29 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:35:29 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:35:29 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:29 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:29 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:35:30 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Aug 29 23:35:30 basement-music volumio[9346]: info: In handleBrowseUri, curUri=spotify Aug 29 23:35:30 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:30 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:30 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:30 basement-music volumio[9346]: info: Preload queue cleared Aug 29 23:35:36 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 23:35:39 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:35:39 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 23:35:41 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1469. Aug 29 23:35:41 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:42 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:42 basement-music upmpdcli[10130]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:35:42 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:35:42 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 23:35:44 basement-music volumio[9346]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 29 23:35:44 basement-music volumio[9346]: info: Received Get System Version Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 23:35:44 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:35:44 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:44 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:44 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:35:51 basement-music go-librespot[9735]: time="2026-08-29T23:35:51-04:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Aug 29 23:35:51 basement-music volumio[9346]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Aug 29 23:35:51 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:35:51 basement-music volumio[9346]: Cannot find translation for source Pandora Radio Aug 29 23:35:51 basement-music volumio[9346]: info: Disabling plugin spop Aug 29 23:35:51 basement-music volumio[9346]: info: Done. Aug 29 23:35:51 basement-music sudo[10146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Aug 29 23:35:51 basement-music sudo[10146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:51 basement-music volumio[9346]: info: Connection to go-librespot Websocket closed Aug 29 23:35:51 basement-music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 23:35:51 basement-music systemd[1]: go-librespot-daemon.service: Killing process 9738 (go-librespot) with signal SIGKILL. Aug 29 23:35:51 basement-music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 23:35:51 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:35:51 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:51 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:51 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:51 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:51 basement-music sudo[10146]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:52 basement-music volumio[9346]: info: Enabling plugin spop Aug 29 23:35:52 basement-music volumio[9346]: info: Loading plugin "spop"... Aug 29 23:35:52 basement-music volumio[9346]: info: PLUGIN START: spop Aug 29 23:35:52 basement-music volumio[9346]: info: Creating Spotify config file Aug 29 23:35:52 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:35:52 basement-music volumio[9346]: info: Done. Aug 29 23:35:52 basement-music volumio[9346]: info: Spotify config file written Aug 29 23:35:52 basement-music systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 29 23:35:52 basement-music volumio[9346]: info: No need to fix Spotify hosts Aug 29 23:35:52 basement-music systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Aug 29 23:35:52 basement-music systemd[1]: welcome.service: Deactivated successfully. Aug 29 23:35:52 basement-music systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 29 23:35:52 basement-music systemd[1]: Stopping welcome.service - Show a welcome message on console... Aug 29 23:35:52 basement-music sudo[10164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:35:52 basement-music sudo[10164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:35:53 basement-music systemd[1]: Starting welcome.service - Show a welcome message on console... Aug 29 23:35:53 basement-music welcome[10168]: Resolved ip:[1] 192.168.1.11 Aug 29 23:35:53 basement-music systemd[1]: Finished welcome.service - Show a welcome message on console. Aug 29 23:35:53 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:53 basement-music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 29 23:35:53 basement-music systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Aug 29 23:35:53 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:35:53 basement-music go-librespot[10176]: go-librespot daemon starting... Aug 29 23:35:53 basement-music sudo[10164]: pam_unix(sudo:session): session closed for user root Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=debug msg="app state loaded" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:35:53 basement-music volumio[9346]: info: New Spotify access tokenBQDzCetx5T... Aug 29 23:35:53 basement-music volumio[9346]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 23:35:53 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:35:53 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:35:53 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:35:53 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:53.386-04:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" available=true connected=true macAddress=b8:27:eb:9b:16:51 ip4Address=192.168.1.11/24 ip6Address= Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 23:35:53 basement-music volumio[9346]: SPOTIFY: User informations: {"account_id":"8vsUgbS6fZ","country":"US","display_name":"Brian Pelletier","email":"brian.pelletier@aloe-me.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lwss8i67puhgza25a49rbpyxi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/lwss8i67puhgza25a49rbpyxi","id":"lwss8i67puhgza25a49rbpyxi","images":[],"product":"premium","type":"user","uri":"spotify:user:lwss8i67puhgza25a49rbpyxi"} Aug 29 23:35:53 basement-music volumio[9346]: info: Spotify Successfully logged in Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:35:53 basement-music volumio[9346]: info: [1788060953619] CoreMusicLibrary::Adding element Spotify Aug 29 23:35:53 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:35:53 basement-music volumio[9346]: Cannot find translation for source Pandora Radio Aug 29 23:35:53 basement-music volumio[9346]: Cannot find translation for source Spotify Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=info msg="zeroconf server listening on port 40587" Aug 29 23:35:53 basement-music go-librespot[10177]: time="2026-08-29T23:35:53-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:35:54 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:35:54.286-04:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 29 23:35:56 basement-music volumio[9346]: info: go-librespot daemon successfully initialized Aug 29 23:35:57 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1470. Aug 29 23:35:57 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:57 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:35:57 basement-music upmpdcli[10187]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:35:57 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:35:57 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:35:57 basement-music volumio[9346]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 23:35:59 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:35:59 basement-music go-librespot[10177]: time="2026-08-29T23:35:59-04:00" level=debug msg="new websocket client" Aug 29 23:35:59 basement-music volumio[9346]: info: Connection to go-librespot Websocket established Aug 29 23:36:01 basement-music volumio[9346]: info: Received OAUTH Data Aug 29 23:36:01 basement-music volumio[9346]: info: Executing Spotify Oauth Login Aug 29 23:36:01 basement-music volumio[9346]: info: Saving Spotify Refresh Token Aug 29 23:36:01 basement-music sudo[10203]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 23:36:01 basement-music sudo[10203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:01 basement-music sudo[10205]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 23:36:01 basement-music sudo[10205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:01 basement-music sudo[10203]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:01 basement-music sudo[10205]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:01 basement-music volumio[9346]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.148 UA: Mozilla/5.0 (Linux; Android 16; SM-S947U Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 29 23:36:02 basement-music volumio[9346]: info: New Spotify access tokenBQB7NAeCTU... Aug 29 23:36:02 basement-music volumio[9346]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:02 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 23:36:02 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:02 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:02 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:02 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:02 basement-music volumio[9346]: info: Listing playlists Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 29 23:36:02 basement-music volumio[9346]: info: Getting Spotify volume Aug 29 23:36:02 basement-music volumio[9346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:02 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:02 basement-music volumio[9346]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 29 23:36:02 basement-music volumio[9346]: SPOTIFY: User informations: {"account_id":"8vsUgbS6fZ","country":"US","display_name":"Brian Pelletier","email":"brian.pelletier@aloe-me.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lwss8i67puhgza25a49rbpyxi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/lwss8i67puhgza25a49rbpyxi","id":"lwss8i67puhgza25a49rbpyxi","images":[],"product":"premium","type":"user","uri":"spotify:user:lwss8i67puhgza25a49rbpyxi"} Aug 29 23:36:02 basement-music volumio[9346]: info: Creating Spotify config file Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:02 basement-music volumio[9346]: info: Spotify config file written Aug 29 23:36:02 basement-music sudo[10210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:36:02 basement-music sudo[10210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:02 basement-music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 23:36:02 basement-music systemd[1]: go-librespot-daemon.service: Killing process 10179 (go-librespot) with signal SIGKILL. Aug 29 23:36:02 basement-music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 23:36:02 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:02 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:02 basement-music volumio[9346]: info: Connection to go-librespot Websocket closed Aug 29 23:36:02 basement-music go-librespot[10212]: go-librespot daemon starting... Aug 29 23:36:02 basement-music sudo[10210]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:02 basement-music go-librespot[10213]: time="2026-08-29T23:36:02-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:02 basement-music go-librespot[10213]: time="2026-08-29T23:36:02-04:00" level=debug msg="app state loaded" Aug 29 23:36:02 basement-music go-librespot[10213]: time="2026-08-29T23:36:02-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:02 basement-music volumio[9346]: info: New Spotify access tokenBQD4KMusA1... Aug 29 23:36:02 basement-music volumio[9346]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 23:36:02 basement-music volumio[9346]: SPOTIFY: User informations: {"account_id":"8vsUgbS6fZ","country":"US","display_name":"Brian Pelletier","email":"brian.pelletier@aloe-me.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lwss8i67puhgza25a49rbpyxi"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/lwss8i67puhgza25a49rbpyxi","id":"lwss8i67puhgza25a49rbpyxi","images":[],"product":"premium","type":"user","uri":"spotify:user:lwss8i67puhgza25a49rbpyxi"} Aug 29 23:36:02 basement-music volumio[9346]: info: Spotify Successfully logged in Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:02 basement-music volumio[9346]: info: [1788060962967] CoreMusicLibrary::Adding element Spotify Aug 29 23:36:02 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:02 basement-music volumio[9346]: Cannot find translation for source Pandora Radio Aug 29 23:36:02 basement-music volumio[9346]: Cannot find translation for source Spotify Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=info msg="zeroconf server listening on port 35867" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="obtained new client token: AAGRienKWnbg4hduwuJZ7suPMpRHZFIZZ2tRRzY/W97jbBh5K5huLqd5Cr4nH6f6TkJV6NdtYJ82cuITjpe+RuFcmYGaiyPp1cXYa23VvmpoZwz9fZHbbvJ1mgEElK0dJkOalK4hslPgk1D2bezQYAuEq7Q1YSVN7xAO+R2+mcfvN9SfWmssFNpx29vs0en9fkhaw8GdolqCaNd8M/wh6lo6HjmHO9Ij2S+P8GDMSBzHDYFexYI0JOU=" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=debug msg="completed challenge" Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:36:03 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:03 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:03 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:03 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:03 basement-music go-librespot[10213]: time="2026-08-29T23:36:03-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:36:03 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:03 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:04 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 23:36:04 basement-music volumio[9346]: info: Received Get System Info Aug 29 23:36:04 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:04 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:04 basement-music volumio[9346]: info: Discovery: Getting this device information Aug 29 23:36:04 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:04 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:04 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:05 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:05 basement-music volumio[9346]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:05 basement-music volumio[9346]: info: go-librespot daemon successfully initialized Aug 29 23:36:05 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:36:05 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:36:05 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:36:05 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:05 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:36:05 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:05 basement-music volumio[9346]: info: [1788060965703] ControllerSpotify::clearAddPlayTrack Aug 29 23:36:05 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:36:05 basement-music volumio[9346]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:06 basement-music volumio[9346]: info: CoreCommandRouter::volumioPlay Aug 29 23:36:06 basement-music volumio[9346]: info: CoreStateMachine::play index undefined Aug 29 23:36:06 basement-music volumio[9346]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 23:36:06 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:06 basement-music volumio[9346]: info: CoreStateMachine::startPlaybackTimer Aug 29 23:36:06 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:06 basement-music volumio[9346]: info: [1788060966452] ControllerSpotify::clearAddPlayTrack Aug 29 23:36:06 basement-music volumio[9346]: info: Sending Spotify command with payload to local API: /player/play Aug 29 23:36:06 basement-music volumio[9346]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:07 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 23:36:07 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:07 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:07 basement-music go-librespot[10222]: go-librespot daemon starting... Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=debug msg="app state loaded" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=info msg="zeroconf server listening on port 44705" Aug 29 23:36:07 basement-music go-librespot[10223]: time="2026-08-29T23:36:07-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=debug msg="obtained new client token: AAGycv7wt35F7a/4C51JzPL0vmHSK/YbCZ89muDgG6ZLm4HJ8oX2POmEzSAp9Jsmn+wqPWYk4oDKldPPT/Gx2hXbfHkZ0nMiex8aK6I4c1tjQi/X/Wa5RA2UfAVOadNVqwv2fqeNhAzVjvCZ6Me5Sc2E2GiMsnama/Ijn40guYEW7fcA3aVafBdgAPScCPu3rwwqv/gWLSqsJl+bV03vlURORDdV/mQvOTsgzUWptkP3/Md8vjROeF8=" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=debug msg="completed challenge" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:08 basement-music go-librespot[10223]: time="2026-08-29T23:36:08-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:36:08 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:08 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:08 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:08 basement-music volumio[9346]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:08 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:08 basement-music volumio[9346]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:09 basement-music volumio[9346]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 29 23:36:09 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 29 23:36:09 basement-music volumio[9346]: info: Creating Spotify config file Aug 29 23:36:09 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:09 basement-music volumio[9346]: info: Spotify config file written Aug 29 23:36:09 basement-music sudo[10233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:36:09 basement-music sudo[10233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:09 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:09 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:09 basement-music go-librespot[10235]: go-librespot daemon starting... Aug 29 23:36:09 basement-music sudo[10233]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=debug msg="app state loaded" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=info msg="zeroconf server listening on port 43977" Aug 29 23:36:09 basement-music go-librespot[10236]: time="2026-08-29T23:36:09-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=debug msg="obtained new client token: AAGFkTeZc6Vcvoo5o7RyowwOTCeEI1RBZatLlQWZaNuPfxKtOvCkJoAh2Xd3GmphvPtJr9o7VeZpAl799z8PQuMBN7hs8u2uTypVF7XTyxJAtP+Ve1cE+U9dmdX2KeEM9I5s/nEj6jINjq5bXjY7ak3iZgVpDUM4p0Q19yq4/JDvdRghIQ2dLXPVU6Joj71h88lGdwcYcmZ4uzei9o3jZMoiX73Rbk+NN22pRJd+KFLxpQDdSBCs" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=debug msg="completed challenge" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:10 basement-music go-librespot[10236]: time="2026-08-29T23:36:10-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:36:10 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:10 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:11 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:11 basement-music volumio[9346]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:11 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 23:36:12 basement-music volumio[9346]: info: go-librespot daemon successfully initialized Aug 29 23:36:12 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1471. Aug 29 23:36:12 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:12 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:12 basement-music upmpdcli[10260]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:36:12 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:12 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:36:13 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 23:36:13 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:13 basement-music volumio[9346]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 29 23:36:13 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 29 23:36:13 basement-music volumio[9346]: info: Creating Spotify config file Aug 29 23:36:13 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:13 basement-music volumio[9346]: info: Spotify config file written Aug 29 23:36:13 basement-music sudo[10263]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:36:13 basement-music sudo[10263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:13 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:13 basement-music go-librespot[10261]: go-librespot daemon starting... Aug 29 23:36:13 basement-music go-librespot[10265]: time="2026-08-29T23:36:13-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:13 basement-music go-librespot[10265]: time="2026-08-29T23:36:13-04:00" level=debug msg="app state loaded" Aug 29 23:36:13 basement-music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 23:36:13 basement-music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 23:36:13 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:13 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:13 basement-music go-librespot[10273]: go-librespot daemon starting... Aug 29 23:36:13 basement-music sudo[10263]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="app state loaded" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=info msg="zeroconf server listening on port 34471" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:14 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="new websocket client" Aug 29 23:36:14 basement-music volumio[9346]: info: Connection to go-librespot Websocket established Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="obtained new client token: AAEKL97jORD2Zr34AcNOXCvLjUe+PJ+0fbkrHbsSMPijfnzBwbS5CXpUTV/AZtoovwuvUQMtoqc7m8lPl0dWsxUQn+TGA7nHvZeZ2xuHqOycve6VYNZMaoDP95h6Y3zSgEm0m3IPJ6GF6vTifIVgDGBa/c8npO/yLq4MRL5kursS21McmbFhnJAsYCiNIhim/CWF/D95IEX0Czl4cJLKoPuIlCbFsO9smuNhIcGAMEsjS46xBjO9zd0=" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=debug msg="completed challenge" Aug 29 23:36:14 basement-music go-librespot[10274]: time="2026-08-29T23:36:14-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:15 basement-music go-librespot[10274]: time="2026-08-29T23:36:15-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:36:15 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:15 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:15 basement-music volumio[9346]: info: Connection to go-librespot Websocket closed Aug 29 23:36:15 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:15 basement-music volumio[9346]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:16 basement-music volumio[9346]: info: go-librespot daemon successfully initialized Aug 29 23:36:17 basement-music volumio[9346]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Aug 29 23:36:17 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Aug 29 23:36:17 basement-music volumio[9346]: info: Creating Spotify config file Aug 29 23:36:17 basement-music volumio[9346]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:17 basement-music volumio[9346]: info: Spotify config file written Aug 29 23:36:17 basement-music sudo[10286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:36:17 basement-music sudo[10286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:17 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:17 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:17 basement-music go-librespot[10288]: go-librespot daemon starting... Aug 29 23:36:17 basement-music sudo[10286]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=debug msg="app state loaded" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:17 basement-music volumio[9346]: info: Getting Spotify volume Aug 29 23:36:17 basement-music volumio[9346]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 29 23:36:17 basement-music volumio[9346]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:17 basement-music volumio[9346]: info: CorePlayQueue::getTrack 1 Aug 29 23:36:17 basement-music volumio[9346]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=info msg="zeroconf server listening on port 41851" Aug 29 23:36:17 basement-music go-librespot[10289]: time="2026-08-29T23:36:17-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=debug msg="obtained new client token: AAGjRLa22pP/XXF670u6VXet+mPhe7yTOXY00X+lnn/vkvVQO6Kv94YFzJFnAans4kMI6loSjl3/b3v4ebrAWG5U4pSENdiJN98pRAF2e451jQnReLvlTlNKybQNdcv9WfYBuCaAaHVdZcpZhANkjdE8vB06xlAt3gLUaSuw1iuq826QJ1Nle4LXUdCFbTZbNuK0/vAXU8K6HvH6wELmQmr2vR4ZXuRjJatnX5gwvg0eFI7BcH38" Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:18 basement-music volumio[9346]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=debug msg="new websocket client" Aug 29 23:36:18 basement-music volumio[9346]: info: Connection to go-librespot Websocket established Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=debug msg="completed challenge" Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:18 basement-music go-librespot[10289]: time="2026-08-29T23:36:18-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 23:36:18 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:18 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:18 basement-music volumio[9346]: info: Connection to go-librespot Websocket closed Aug 29 23:36:18 basement-music volumio[9346]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:36:18 basement-music volumio[9346]: Error: socket hang up Aug 29 23:36:18 basement-music volumio[9346]: at connResetException (node:internal/errors:720:14) Aug 29 23:36:18 basement-music volumio[9346]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 29 23:36:18 basement-music volumio[9346]: at Socket.emit (node:events:526:35) Aug 29 23:36:18 basement-music volumio[9346]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 29 23:36:18 basement-music volumio[9346]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 29 23:36:18 basement-music volumio[9346]: code: 'ECONNRESET', Aug 29 23:36:18 basement-music volumio[9346]: response: undefined Aug 29 23:36:18 basement-music volumio[9346]: } Aug 29 23:36:18 basement-music volumio[9346]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:36:20 basement-music sudo[10327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 23:35' Aug 29 23:36:20 basement-music sudo[10327]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"