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) Aug 29 23:36:20 basement-music sudo[10327]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:21 basement-music volumio-remote-updater[670]: [2026-08-29 23:36:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 29 23:36:21 basement-music volumio-remote-updater[670]: [2026-08-29 23:36:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 29 23:36:21 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:21.202-04:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 29 23:36:21 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:21.206-04:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 23:36:21 basement-music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:21 basement-music systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 29 23:36:21 basement-music systemd[1]: volumio.service: Consumed 1min 21.986s CPU time. Aug 29 23:36:21 basement-music systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 29 23:36:21 basement-music systemd[1]: dynamicswap.service: Deactivated successfully. Aug 29 23:36:21 basement-music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7. Aug 29 23:36:21 basement-music systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 29 23:36:21 basement-music systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 29 23:36:21 basement-music systemd[1]: volumio.service: Consumed 1min 21.986s CPU time. Aug 29 23:36:21 basement-music systemd[1]: Started volumio.service - Volumio Backend Module. Aug 29 23:36:21 basement-music systemd[1]: dynamicswap.service: Deactivated successfully. Aug 29 23:36:21 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 23:36:21 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:21 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:21 basement-music go-librespot[10359]: go-librespot daemon starting... Aug 29 23:36:21 basement-music go-librespot[10360]: time="2026-08-29T23:36:21-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:21 basement-music go-librespot[10360]: time="2026-08-29T23:36:21-04:00" level=debug msg="app state loaded" Aug 29 23:36:21 basement-music go-librespot[10360]: time="2026-08-29T23:36:21-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:22 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:22.209-04:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-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:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-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:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-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:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=info msg="zeroconf server listening on port 42679" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=debug msg="obtained new client token: AAHl9I/EiDSizRIm/sJ5LeJrG2Y6/5wiCSevjGBYEMQlHjAMHe++X86/5voSO44B+gB60tdcqGgR6fmxSOX9hx7tGnVqM3RZe3hMwTZRRPlDWul/tKL5KPmFEATTixR7sk7SDapNcrLpIjujazVS2eAftd0ajW6xL8edsTfOyK6E4hjdKdA686iH/ahzar0cXfxP/QrYFnp13Yw6v5s8DX0h22uS8rf9Y5Uqz5dw+jsB8/nfyKD11lE=" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=debug msg="completed challenge" Aug 29 23:36:22 basement-music go-librespot[10360]: time="2026-08-29T23:36:22-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:23 basement-music go-librespot[10360]: time="2026-08-29T23:36:23-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:23 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:23 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:23 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:23.211-04:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 29 23:36:25 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:25 basement-music volumio[10344]: info: ----- Volumio3 ---- Aug 29 23:36:25 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:25 basement-music volumio[10344]: info: ----- System startup ---- Aug 29 23:36:25 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:26 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 23:36:26 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:26 basement-music volumio-remote-updater[670]: [2026-08-29 23:36:26] [connect] Successful connection Aug 29 23:36:26 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:26 basement-music go-librespot[10375]: go-librespot daemon starting... Aug 29 23:36:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-04:00" level=debug msg="app state loaded" Aug 29 23:36:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:26 basement-music volumio[10344]: info: MYVOLUMIO Environment detected Aug 29 23:36:26 basement-music volumio[10344]: info: Plugin folders cleanup Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning into folder /volumio/app/plugins/ Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category audio_interface Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category miscellanea Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category music_service Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category plugins.json Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category system_controller Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category user_interface Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning into folder /data/plugins/ Aug 29 23:36:26 basement-music volumio[10344]: info: Scanning category music_service Aug 29 23:36:26 basement-music volumio[10344]: info: Plugin folders cleanup completed Aug 29 23:36:26 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:26 basement-music volumio[10344]: info: ----- Core plugins startup ---- Aug 29 23:36:26 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:26 basement-music volumio[10344]: info: Loading plugins from folder /volumio/app/plugins/ Aug 29 23:36:26 basement-music volumio[10344]: info: Adding plugin upnp to MyMusic Plugins Aug 29 23:36:26 basement-music volumio[10344]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 29 23:36:26 basement-music volumio[10344]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 29 23:36:26 basement-music volumio[10344]: info: Loading plugins from folder /data/plugins/ Aug 29 23:36:26 basement-music volumio[10344]: info: Loading plugin "system"... Aug 29 23:36:26 basement-music volumio[10344]: info: Loading plugin "appearance"... Aug 29 23:36:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-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:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-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:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-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:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-04:00" level=info msg="zeroconf server listening on port 34321" Aug 29 23:36:26 basement-music go-librespot[10376]: time="2026-08-29T23:36:26-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-04:00" level=debug msg="obtained new client token: AAFSuBN5UmWZgPVjYHsKHUWUvdJ+Dd1LMnuOw3EjiZTiFWHXAaj+RLDzm1NWGimONjpkGvYb3frueaoOHebj8Ok1e0tIqybKSeWbQQffn3r214785HFnnJGYyquWzKJPvdMS5OMJ01WkRu2v4i4w9K+SdMNXdDxsHb+seC2gUdfqT0tCe7xHX/EpMn/6CD3dN8Yvnl4mbTzCaBgi0nAAFDP6GsejCg1oUS74jGRzJpbV4i23nG39" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-04:00" level=debug msg="completed challenge" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:27 basement-music go-librespot[10376]: time="2026-08-29T23:36:27-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:27 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:27 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:27 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1472. Aug 29 23:36:27 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:27 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:27 basement-music upmpdcli[10391]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:36:27 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:27 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "network"... Aug 29 23:36:28 basement-music volumio[10344]: info: Refreshing Cached IP Addresses Aug 29 23:36:28 basement-music sudo[10393]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 23:36:28 basement-music sudo[10393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:28 basement-music sudo[10395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "services"... Aug 29 23:36:28 basement-music sudo[10395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:28 basement-music sudo[10393]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "volumio5onboarding"... Aug 29 23:36:28 basement-music sudo[10395]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:28 basement-music sudo[10402]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 29 23:36:28 basement-music sudo[10402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "alsa_controller"... Aug 29 23:36:28 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "wizard"... Aug 29 23:36:28 basement-music volumio[10344]: info: Loading plugin "networkfs"... Aug 29 23:36:29 basement-music volumio[10344]: info: Starting Udev Watcher for removable devices Aug 29 23:36:29 basement-music volumio[10344]: info: Ignoring mount for partition: boot Aug 29 23:36:29 basement-music volumio[10344]: info: Ignoring mount for partition: volumio Aug 29 23:36:29 basement-music volumio[10344]: info: Ignoring mount for partition: volumio_data Aug 29 23:36:29 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 23:36:29 basement-music volumio[10344]: info: Loading plugin "volumio_command_line_client"... Aug 29 23:36:29 basement-music volumio[10344]: info: Plugin upnp is not enabled Aug 29 23:36:29 basement-music volumio[10344]: info: Loading plugin "my_music"... Aug 29 23:36:29 basement-music volumio[10344]: info: Loading plugin "mpd"... Aug 29 23:36:29 basement-music sudo[10402]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:29 basement-music volumio[10344]: info: Loading plugin "upnp_browser"... Aug 29 23:36:29 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:29.890-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.148:42872,00:00:00:00:00:00%01 @ 0x2d42900" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Aug 29 23:36:30 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 23:36:30 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:30 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:30 basement-music go-librespot[10426]: go-librespot daemon starting... Aug 29 23:36:30 basement-music go-librespot[10427]: time="2026-08-29T23:36:30-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:30 basement-music go-librespot[10427]: time="2026-08-29T23:36:30-04:00" level=debug msg="app state loaded" Aug 29 23:36:30 basement-music go-librespot[10427]: time="2026-08-29T23:36:30-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-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:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-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:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-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:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=info msg="zeroconf server listening on port 40989" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=debug msg="obtained new client token: AAGzyJU7oUOFc56NUNkfwZrmg9Z8b0DtXEg2aCJzMK6tStd4WT1/FZVlKjNk9iAO+zWGp+V7sjesBN+FxXsvCB2JBC3YasiFsbfw4SIFPwRG3Hm9WGdmNRr8AjRU0Uhr0tOErfTYeI63JbiSwv5NCCbhm/R60cuCUHHYk7cvV6jPkRoUdY6JmT9lfbqWq7nc+d+R+Vxe5YYsy1WJP3wirY+rgy/wNr1F8vPkASGJ7ttc8Ikn6EK9Trc=" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=debug msg="completed challenge" Aug 29 23:36:31 basement-music go-librespot[10427]: time="2026-08-29T23:36:31-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:32 basement-music go-librespot[10427]: time="2026-08-29T23:36:32-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:32 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:32 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:32 basement-music volumio[10344]: info: Starting UPNP Browser Aug 29 23:36:32 basement-music volumio[10344]: info: Loading plugin "alarm-clock"... Aug 29 23:36:33 basement-music volumio[10344]: info: Plugin airplay_emulation is not enabled Aug 29 23:36:33 basement-music volumio[10344]: info: Loading plugin "last_100"... Aug 29 23:36:33 basement-music volumio[10344]: info: Loading plugin "webradio"... Aug 29 23:36:33 basement-music volumio[10344]: info: Loading plugin "i2s_dacs"... Aug 29 23:36:33 basement-music volumio[10344]: info: I2S DAC not set, start Auto-detection Aug 29 23:36:33 basement-music volumio[10344]: info: Loading plugin "volumiodiscovery"... Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** For more information see Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 23:36:33 basement-music volumio[10344]: *** WARNING *** For more information see Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** For more information see Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 29 23:36:33 basement-music node[10344]: *** WARNING *** For more information see Aug 29 23:36:33 basement-music volumio[10344]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 29 23:36:33 basement-music volumio[10344]: info: Discovery: Started advertising with name: Basement Music Aug 29 23:36:33 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 29 23:36:33 basement-music volumio[10344]: info: Loading plugin "spop"... Aug 29 23:36:34 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:34.214-04:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:51806->127.0.0.1:3000: i/o timeout" Aug 29 23:36:35 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 23:36:35 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:35 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:35 basement-music go-librespot[10439]: go-librespot daemon starting... Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "outputs"... Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "albumart"... Aug 29 23:36:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-04:00" level=debug msg="app state loaded" Aug 29 23:36:35 basement-music volumio[10344]: info: Plugin example_plugin is not enabled Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "inputs"... Aug 29 23:36:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "updater_comm"... Aug 29 23:36:35 basement-music volumio[10344]: info: Plugin mpdemulation is not enabled Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "rest_api"... Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "websocket"... Aug 29 23:36:35 basement-music volumio[10344]: info: Starting Socket.io Server version 1.7.4 Aug 29 23:36:35 basement-music volumio[10344]: info: Loading plugin "pandora"... Aug 29 23:36:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-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:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-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:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-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:35 basement-music go-librespot[10440]: time="2026-08-29T23:36:35-04:00" level=info msg="zeroconf server listening on port 42607" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=debug msg="obtained new client token: AAGBgQVLSwK54gEToyBaxeG9166girwR2EQz0LQEXMXHeUJd8vDvG0KSeUJOXckylVyGu17eBFq+/1nQFy5CWQ6rRGSn1M21TLKWafYQUEr78OnsHePXMCiXjF+V6h+xZaGGsAyrfeaHo4jX5dh2oYjQE+r5VPIZMGQ8rsQMScdP6+Oca6bukE3EycJr/cTm/SCJ/NNBif5r3BFiafHNjwedEtgohHs3EN+uty0SmPA2MG/vgjq6" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=debug msg="completed challenge" Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:36 basement-music volumio[10446]: Forking 3 albumart workers Aug 29 23:36:36 basement-music go-librespot[10440]: time="2026-08-29T23:36:36-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:36 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:36 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:38 basement-music volumio[10344]: info: Applying required configuration parameters for plugin pandora Aug 29 23:36:38 basement-music volumio[10344]: info: Loading i18n strings for locale en Aug 29 23:36:38 basement-music volumio[10344]: Updating browse sources language Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:38 basement-music volumio-remote-updater[670]: [2026-08-29 23:36:38] [connect] Successful connection Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::initPlayerControls Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 23:36:38 basement-music volumio[10344]: Express server listening on port 3000 Aug 29 23:36:38 basement-music volumio[10344]: [Metrics] WebUI: 14s 675.79ms Aug 29 23:36:38 basement-music volumio[10344]: info: CoreStateMachine::resetVolumioState Aug 29 23:36:38 basement-music volumio[10344]: info: CoreStateMachine::getcurrentVolume Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 23:36:38 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 23:36:39 basement-music volumio[10344]: info: Volumio Network Manager: Network status updated: 1 Aug 29 23:36:39 basement-music volumio[10459]: Starting albumart workers Aug 29 23:36:39 basement-music volumio[10460]: Starting albumart workers Aug 29 23:36:39 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 1 Aug 29 23:36:39 basement-music volumio[10461]: Starting albumart workers Aug 29 23:36:39 basement-music volumio[10344]: info: VolumeController:: Volume=100 Mute =false Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::pushState Aug 29 23:36:39 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushState Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::updateTrackBlock Aug 29 23:36:39 basement-music volumio[10344]: info: CorePlayQueue::getTrackBlock Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 23:36:39 basement-music volumio[10344]: info: Reloading queue from file Aug 29 23:36:39 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 2 Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::setRepeat null single undefined Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::pushState Aug 29 23:36:39 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushState Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::setRandom null Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::pushState Aug 29 23:36:39 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushState Aug 29 23:36:39 basement-music volumio[10344]: info: Setting Device type: Raspberry PI Aug 29 23:36:39 basement-music volumio[10344]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 29 23:36:39 basement-music volumio[10344]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a22082 Aug 29 23:36:39 basement-music volumio[10344]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 29 23:36:39 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 3 Aug 29 23:36:39 basement-music volumio5-onboarding[1886]: time=2026-08-29T23:36:39.882-04:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Aug 29 23:36:39 basement-music volumio[10344]: 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: 4 Aug 29 23:36:39 basement-music volumio[10344]: info: VolumeController:: Volume=100 Mute =false Aug 29 23:36:39 basement-music volumio[10344]: info: CoreStateMachine::pushState Aug 29 23:36:39 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:39 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushState Aug 29 23:36:39 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 23:36:39 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:39 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 5 Aug 29 23:36:40 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:40 basement-music volumio[10344]: info: Discovery: adding 1b117ae5-82b5-4c2b-82d4-d3a8880753c2 Aug 29 23:36:40 basement-music go-librespot[10518]: go-librespot daemon starting... Aug 29 23:36:40 basement-music volumio[10344]: info: Discovery: Found device Basement Music Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:40 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:40 basement-music volumio[10344]: info: Discovery: this is already registered, 1b117ae5-82b5-4c2b-82d4-d3a8880753c2 Aug 29 23:36:40 basement-music volumio[10344]: info: Discovery: Found device Basement Music Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:40 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:40 basement-music volumio[10344]: 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:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-04:00" level=debug msg="app state loaded" Aug 29 23:36:40 basement-music volumio[10344]: info: Completed loading Core Plugins Aug 29 23:36:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:40 basement-music volumio[10344]: info: Preparing to generate the ALSA configuration file Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:40 basement-music volumio[10344]: info: Discovery: Getting this device information Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:40 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:40 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Aug 29 23:36:40 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 7 Aug 29 23:36:40 basement-music volumio[10344]: 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: 8 Aug 29 23:36:40 basement-music volumio[10344]: info: Asound.conf file unchanged, so no further update is needed Aug 29 23:36:40 basement-music volumio[10344]: info: Output device has changed, restarting MPD Aug 29 23:36:40 basement-music volumio[10344]: info: ___________ START PLUGINS ___________ Aug 29 23:36:40 basement-music volumio[10344]: info: ControllerMpd::onStart: Initializing MPD Aug 29 23:36:40 basement-music volumio[10344]: info: Creating MPD Configuration file Aug 29 23:36:40 basement-music sudo[10540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 23:36:40 basement-music sudo[10538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 23:36:40 basement-music sudo[10531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 23:36:40 basement-music sudo[10540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:40 basement-music sudo[10531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:40 basement-music sudo[10538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:40 basement-music sudo[10531]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:40 basement-music volumio[10344]: info: [1788061000718] CoreMusicLibrary::Adding element Media Servers Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:40 basement-music volumio[10344]: info: UPNP Browser: Client initialized successfully Aug 29 23:36:40 basement-music sudo[10544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 23:36:40 basement-music sudo[10544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:40 basement-music sudo[10544]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:40 basement-music volumio[10344]: info: [1788061000816] CoreMusicLibrary::Adding element Last_100 Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:40 basement-music sudo[10548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 23:36:40 basement-music sudo[10548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:40 basement-music volumio[10344]: info: [1788061000832] CoreMusicLibrary::Adding element Webradio Aug 29 23:36:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-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:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-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:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-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:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:40 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 23:36:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-04:00" level=info msg="zeroconf server listening on port 39059" Aug 29 23:36:40 basement-music volumio[10344]: info: Initializing BBC Radios Aug 29 23:36:40 basement-music systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 29 23:36:40 basement-music sudo[10540]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:40 basement-music go-librespot[10519]: time="2026-08-29T23:36:40-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:41 basement-music systemd[1]: mpd.service: Deactivated successfully. Aug 29 23:36:41 basement-music systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 23:36:41 basement-music systemd[1]: mpd.service: Consumed 6.194s CPU time. Aug 29 23:36:41 basement-music systemd[1]: mpd.socket: Deactivated successfully. Aug 29 23:36:41 basement-music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 23:36:41 basement-music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 23:36:41 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 23:36:41 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 23:36:41 basement-music volumio[10344]: info: Creating Spotify config file Aug 29 23:36:41 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:41 basement-music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-04:00" level=debug msg="obtained new client token: AAFmYz7Mfh1YGucxM1UFUin3g9NLd4xQtLKpVlQCNREylvj0Neq09xj/oWMVSF8Gu7ppSBb74Fjd86PZf5qLMN+z4HY/qbYmw2f84JuhkLBiqBQyPOQVbr7D9HDYBAib/EUWLRpr89y5O/u4l6egfEERh+X/sxhQN15wnj9NMOm0PnmRHoik2NUeVZku1DzaSQwOpWVv7LAnD1Ul+oF3P0BI39pV8KY7mJ4BCE/Ddr9LERCvsepI" Aug 29 23:36:41 basement-music systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-04:00" level=debug msg="completed challenge" Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:41 basement-music sudo[10570]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 23:36:41 basement-music sudo[10570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 23:36:41 basement-music sudo[10570]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:41 basement-music go-librespot[10519]: time="2026-08-29T23:36:41-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:41 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:41 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:41 basement-music volumio[10344]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:41 basement-music volumio[10344]: info: [1788061001855] CoreMusicLibrary::Adding element Pandora Radio Aug 29 23:36:41 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:41 basement-music volumio[10344]: Cannot find translation for source Pandora Radio Aug 29 23:36:41 basement-music volumio[10344]: info: [1788061001864] ControllerPandora::initialSetup Aug 29 23:36:41 basement-music volumio[10344]: info: [1788061001871] ControllerPandora::checkPing Aug 29 23:36:41 basement-music volumio[10344]: info: Volumio Calling Home Aug 29 23:36:42 basement-music volumio-remote-updater[670]: [2026-08-29 23:36:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788060998 101 Aug 29 23:36:42 basement-music volumio[10344]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 9 Aug 29 23:36:42 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 10 Aug 29 23:36:42 basement-music volumio[10344]: info: MPD Permissions set Aug 29 23:36:42 basement-music volumio[10344]: info: MPD Permissions set Aug 29 23:36:42 basement-music volumio[10344]: info: Volumio called home Aug 29 23:36:42 basement-music volumio[10344]: info: Spotify config file written Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:42 basement-music volumio[10344]: info: Discovery: Getting this device information Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:42 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:42 basement-music sudo[10583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 23:36:42 basement-music sudo[10583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:42 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:42 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:42 basement-music go-librespot[10585]: go-librespot daemon starting... Aug 29 23:36:42 basement-music systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1473. Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:42 basement-music systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Aug 29 23:36:42 basement-music sudo[10583]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 23:36:42 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 23:36:42 basement-music go-librespot[10591]: time="2026-08-29T23:36:42-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:42 basement-music go-librespot[10591]: time="2026-08-29T23:36:42-04:00" level=debug msg="app state loaded" Aug 29 23:36:42 basement-music volumio[10344]: info: No need to fix Spotify hosts Aug 29 23:36:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:43 basement-music upmpdcli[10597]: Could not open config: /tmp/upmpdcli.conf Aug 29 23:36:43 basement-music systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:43 basement-music systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Aug 29 23:36:43 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 11 Aug 29 23:36:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-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:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-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:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-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:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-04:00" level=info msg="zeroconf server listening on port 46483" Aug 29 23:36:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:43 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.129 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 11 Aug 29 23:36:43 basement-music volumio[10344]: verbose: New Socket.io Connection to 192.168.1.11:3000 from 192.168.1.148 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Aug 29 23:36:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-04:00" level=debug msg="obtained new client token: AAHSaVjSyPC3PKxCMIOr/kLFS1sKMI/hu/EkI9deS/lnmWObsraERfCC+qAKjtGWcQ3WraVsp3MFwK+FcueVz6t7xOdNX/izB3EImamLTSujbv8k9yOr4Yp+kCJqmc7yfMrFi5k2kVtb2VY0Fix/FpcK1jahocJJbTjKA1vDwEbrjekUnv1tdWOYtKIBaSqWSRUJlkbNxOGMJaXcjNkEVLMRNWizYHEHrfxDZWblB/l7/+zAoVrLeMY=" Aug 29 23:36:43 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 29 23:36:43 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 29 23:36:43 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 13 Aug 29 23:36:43 basement-music go-librespot[10591]: time="2026-08-29T23:36:43-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:44 basement-music go-librespot[10591]: time="2026-08-29T23:36:44-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:44 basement-music go-librespot[10591]: time="2026-08-29T23:36:44-04:00" level=debug msg="completed challenge" Aug 29 23:36:44 basement-music volumio[10344]: info: New Spotify access tokenBQAyGZrCYe... Aug 29 23:36:44 basement-music volumio[10344]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 23:36:44 basement-music volumio[10344]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 13 Aug 29 23:36:44 basement-music go-librespot[10591]: time="2026-08-29T23:36:44-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 23:36:44 basement-music volumio[10344]: info: Received Get System Info Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:44 basement-music volumio[10344]: info: Discovery: Getting this device information Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: Listing playlists Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetQueue Aug 29 23:36:44 basement-music volumio[10344]: info: CoreStateMachine::getQueue Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getQueue Aug 29 23:36:44 basement-music go-librespot[10591]: time="2026-08-29T23:36:44-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:44 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:44 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:44 basement-music volumio[10344]: 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: 13 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 23:36:44 basement-music volumio[10344]: info: Received Get System Info Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 23:36:44 basement-music volumio[10344]: info: Discovery: Getting this device information Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: info: Listing playlists Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioGetState Aug 29 23:36:44 basement-music volumio[10344]: info: CorePlayQueue::getTrack 0 Aug 29 23:36:44 basement-music volumio[10344]: 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:44 basement-music volumio[10344]: info: Spotify Successfully logged in Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 23:36:44 basement-music volumio[10344]: info: [1788061004916] CoreMusicLibrary::Adding element Spotify Aug 29 23:36:44 basement-music volumio[10344]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 23:36:44 basement-music volumio[10344]: Cannot find translation for source Pandora Radio Aug 29 23:36:44 basement-music volumio[10344]: Cannot find translation for source Spotify Aug 29 23:36:46 basement-music volumio[10344]: info: go-librespot daemon successfully initialized Aug 29 23:36:47 basement-music volumio[10344]: info: [1788061007016] [Pandora] checkPing: ***LOOKS GOOD, ICE DOWN THE BEERS IN THE COOLER*** Aug 29 23:36:47 basement-music volumio[10344]: info: [1788061007018] ControllerPandora::checkHTTP Aug 29 23:36:47 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 23:36:47 basement-music mpd[10578]: 2026-08-29T23:36:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 23:36:47 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:47 basement-music go-librespot[10613]: go-librespot daemon starting... Aug 29 23:36:47 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:47 basement-music systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 23:36:47 basement-music sudo[10548]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:47 basement-music sudo[10538]: pam_unix(sudo:session): session closed for user root Aug 29 23:36:47 basement-music go-librespot[10614]: time="2026-08-29T23:36:47-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:47 basement-music go-librespot[10614]: time="2026-08-29T23:36:47-04:00" level=debug msg="app state loaded" Aug 29 23:36:47 basement-music go-librespot[10614]: time="2026-08-29T23:36:47-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:47 basement-music volumio[10344]: error: MPD error: The expression evaluated to a falsy value: Aug 29 23:36:47 basement-music volumio[10344]: assert.ok(self.idling) Aug 29 23:36:47 basement-music volumio[10344]: error: The expression evaluated to a falsy value: Aug 29 23:36:47 basement-music volumio[10344]: assert.ok(self.idling) Aug 29 23:36:47 basement-music volumio[10344]: info: MPD running with PID10578 Aug 29 23:36:47 basement-music volumio[10344]: ,establishing connection Aug 29 23:36:47 basement-music volumio[10344]: error: updateQueue error: null Aug 29 23:36:47 basement-music volumio[10344]: error: updateQueue error: null Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-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:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-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:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-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:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=info msg="zeroconf server listening on port 40397" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=debug msg="obtained new client token: AAFDAlvZjldcm+I/Oj3qqUGt5vw0irpWd64MtLnb0aiIv19QhLMCtMnD7LgOKhs5Yh/PYP8MrFfOs3L7pgRTm81EZDVFG/fH/Fvs8ybgpDUSkDGqHAPB5xkUeFqWTmsQwyUwI4T15t0fhBR2QVXM/Xws/4kVAumPKxZBXbRet7KxqwE7NNUC9NokgdqCkkMxi+fWxvj1y5UBG/E2MQ08saUQXHDHQ5o1L8EwL28bMRt9p/Iokon/0ds=" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=debug msg="completed challenge" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:48 basement-music go-librespot[10614]: time="2026-08-29T23:36:48-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:48 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:48 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:49 basement-music volumio[10344]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:49 basement-music volumio[10344]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:51 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 23:36:51 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:52 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:52 basement-music go-librespot[10639]: go-librespot daemon starting... Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="app state loaded" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012396] [Pandora] checkHTTP: ***CRACK THE BEERS WE HAVE INTERNET*** Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012397] ControllerPandora::initializeMQTT Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012398] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012400] ControllerPandora::PandoraHandler::init Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012402] ControllerPandora::PandoraHandler::loadErrorCodes Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012405] ControllerPandora::validateAndSetAccountOptions Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012407] ControllerPandora::PandoraHandler::setAccountOptions Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012411] ControllerPandora::flushPandora Aug 29 23:36:52 basement-music volumio[10344]: info: CorePlayQueue::getQueue Aug 29 23:36:52 basement-music volumio[10344]: info: CorePlayQueue::clearAddPlayQueue Aug 29 23:36:52 basement-music volumio[10344]: info: CorePlayQueue::saveQueue Aug 29 23:36:52 basement-music volumio[10344]: info: CoreCommandRouter::serviceClearAddPlayTracks Aug 29 23:36:52 basement-music volumio[10344]: error: WARNING: No clearAddPlayTracks method for service spop Aug 29 23:36:52 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012441] [Pandora] PreventAuthTimeout::init: Timer loaded Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012442] [Pandora] PreventAuthTimeout::init: Interval set to 10800000 ms Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012442] [Pandora] PreventAuthTimeout::init: Starting delayed timer after next interval Aug 29 23:36:52 basement-music volumio[10344]: info: [1788061012444] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-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:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-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:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-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:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=info msg="zeroconf server listening on port 39599" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:52 basement-music volumio[10344]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 23:36:52 basement-music volumio[10344]: info: Initializing connection to go-librespot Websocket Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="obtained new client token: AAEWucrSpGSF5bCrjVE8CeBFgBz9ERq7IBtb93q3z/nWtpSCOiAjQVEus73JCszmAv8KzpWV7gRA5C79e3qKhm19GTFerHwC6z8KJi2TFQj1ahD1yRz5Dye6B46ahu3Ybt0ob7/XUH2kKtYAq5IoRx1W7Q2504uHXsEc+hgZ6dWw8/8yypFi4MP8Mt2qw8qI07ltN0vhicKRTnbCN5tTXZtPuxBC5wTLUX0Hbad9gxRcAxY8Vteohzo=" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="new websocket client" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:52 basement-music volumio[10344]: info: Connection to go-librespot Websocket established Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:52 basement-music go-librespot[10640]: time="2026-08-29T23:36:52-04:00" level=debug msg="completed challenge" Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013056] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: [<=- Logged in to Pandora Servers -=>] Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013069] [Pandora] validateAndSetAccountOptions: ***DEBUG*** self.loggedIn: true Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013071] [Pandora] ExpireOldTracks::init: Timer loaded Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013072] [Pandora] ExpireOldTracks::init: Interval set to 300000 ms Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013072] [Pandora] ExpireOldTracks::init: Starting delayed timer after next interval Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013074] ControllerPandora::PandoraHandler::fillStationData Aug 29 23:36:53 basement-music go-librespot[10640]: time="2026-08-29T23:36:53-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013219] [Pandora] PandoraHandler::setMaxStationTracks: 16 Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013220] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Aug 29 23:36:53 basement-music volumio[10344]: info: [1788061013222] ControllerPandora::flushPandora Aug 29 23:36:53 basement-music volumio[10344]: info: CorePlayQueue::getQueue Aug 29 23:36:53 basement-music volumio[10344]: info: CorePlayQueue::clearAddPlayQueue Aug 29 23:36:53 basement-music volumio[10344]: info: CorePlayQueue::saveQueue Aug 29 23:36:53 basement-music volumio[10344]: info: CoreCommandRouter::serviceClearAddPlayTracks Aug 29 23:36:53 basement-music volumio[10344]: error: WARNING: No clearAddPlayTracks method for service spop Aug 29 23:36:53 basement-music volumio[10344]: info: CoreCommandRouter::volumioPushQueue Aug 29 23:36:53 basement-music volumio[10344]: info: Completed starting Core Plugins Aug 29 23:36:53 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:53 basement-music volumio[10344]: info: ----- MyVolumio plugins startup ---- Aug 29 23:36:53 basement-music volumio[10344]: info: ------------------------------------------- Aug 29 23:36:53 basement-music volumio[10344]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 29 23:36:53 basement-music go-librespot[10640]: time="2026-08-29T23:36:53-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:53 basement-music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 23:36:53 basement-music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 23:36:53 basement-music volumio[10344]: info: Connection to go-librespot Websocket closed Aug 29 23:36:56 basement-music volumio[10344]: info: Getting Spotify volume Aug 29 23:36:56 basement-music volumio[10344]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:36:56 basement-music volumio[10344]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 23:36:56 basement-music volumio[10344]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 23:36:56 basement-music volumio[10344]: errno: -111, Aug 29 23:36:56 basement-music volumio[10344]: code: 'ECONNREFUSED', Aug 29 23:36:56 basement-music volumio[10344]: syscall: 'connect', Aug 29 23:36:56 basement-music volumio[10344]: address: '127.0.0.1', Aug 29 23:36:56 basement-music volumio[10344]: port: 9879, Aug 29 23:36:56 basement-music volumio[10344]: response: undefined Aug 29 23:36:56 basement-music volumio[10344]: } Aug 29 23:36:56 basement-music volumio[10344]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 23:36:56 basement-music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 23:36:56 basement-music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:56 basement-music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 23:36:56 basement-music go-librespot[10663]: go-librespot daemon starting... Aug 29 23:36:56 basement-music go-librespot[10664]: time="2026-08-29T23:36:56-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 23:36:56 basement-music go-librespot[10664]: time="2026-08-29T23:36:56-04:00" level=debug msg="app state loaded" Aug 29 23:36:56 basement-music go-librespot[10664]: time="2026-08-29T23:36:56-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-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:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-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:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-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:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=info msg="zeroconf server listening on port 42395" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=debug msg="obtained new client token: AAFAZJycOk8KaLLxpSS98xUZTPP5w1+6s/Rom1WPUKsACct+jPTHstMeSV43MSjPKxwQwl7eXR2LO6bMHQfsyes6uQUhgLz5Jleytr4DndUaBSpvReHOQ3Tc20lchmToATjAgLQGACn+Bahd9xlreWP9FtwDDSxowFPBWMsZZutCAxHMEZQyhlNbKx1ukQ7b7CYRaI3aO4hoOk4AYHsKavYqsCtEKRaDS7Bv92+8kcS+z+gyz4jDZXA=" Aug 29 23:36:57 basement-music sudo[10675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 23:35' Aug 29 23:36:57 basement-music sudo[10675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=debug msg="completed keyexchange" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=debug msg="completed challenge" Aug 29 23:36:57 basement-music go-librespot[10664]: time="2026-08-29T23:36:57-04:00" level=info msg="authenticated AP" username="lw*********************xi" Aug 29 23:36:57 basement-music nmbd[1364]: [2026/08/29 23:36:57.661875, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 29 23:36:57 basement-music nmbd[1364]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.11 for name WORKGROUP<1d>. Aug 29 23:36:57 basement-music nmbd[1364]: This response was from IP 192.168.1.34, reporting an IP address of 192.168.1.34. 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"