-- Logs begin at Sat 2025-08-30 23:05:35 UTC, end at Mon 2025-09-01 13:39:16 UTC. -- Sep 01 13:38:00 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:00 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:3OFlfeoUpci9pBymVjbgUP Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:3OFlfeoUpci9pBymVjbgUP Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:00 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:2X1b7aYWmGXbJBEvlVNqOZ Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:2X1b7aYWmGXbJBEvlVNqOZ Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:3uFrA4ZOGt2y1aMtkpVAoD Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:3uFrA4ZOGt2y1aMtkpVAoD Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:3MWZxLpZPDeU8XkiJ5ImSm Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:3MWZxLpZPDeU8XkiJ5ImSm Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:1MND0FeTNZQdOGqYd6cLVW Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:1MND0FeTNZQdOGqYd6cLVW Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:3EkzY1fYGeBhuHW7IsjrJX Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:3EkzY1fYGeBhuHW7IsjrJX Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:4IQcIU3hSJhGcFgWEEtqop Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:4IQcIU3hSJhGcFgWEEtqop Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:1Z2gPl9VryxZJflcnryPDe Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:1Z2gPl9VryxZJflcnryPDe Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:518n2hROV7WthEddhLTNhq Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:518n2hROV7WthEddhLTNhq Sep 01 13:38:00 volumio volumio[867]: info: Adding Item to queue: spotify:track:7n8EPanEblQV3YCoy76iiP Sep 01 13:38:00 volumio volumio[867]: info: Using cached record of: spotify:track:7n8EPanEblQV3YCoy76iiP Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:00 volumio volumio[867]: info: CoreStateMachine::startPlaybackTimer Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:00 volumio volumio[867]: info: [1756733880276] ControllerSpotify::clearAddPlayTrack Sep 01 13:38:00 volumio volumio[867]: info: Sending Spotify command with payload to local API: /player/play Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=debug msg="resolved context of track" uri="spotify:track:3OFlfeoUpci9pBymVjbgUP" Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3OFlfeoUpci9pBymVjbgUP" Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3OFlfeoUpci9pBymVjbgUP" Sep 01 13:38:00 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:00 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:00 volumio volumio[867]: info: Listing playlists Sep 01 13:38:00 volumio volumio[867]: info: Listing playlists Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=trace msg="emitting websocket event: will_play" Sep 01 13:38:00 volumio volumio[867]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3OFlfeoUpci9pBymVjbgUP","play_origin":"go-librespot"}} Sep 01 13:38:00 volumio volumio[867]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3OFlfeoUpci9pBymVjbgUP","play_origin":"go-librespot"}} Sep 01 13:38:00 volumio go-librespot[29895]: time="2025-09-01T13:38:00Z" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:3OFlfeoUpci9pBymVjbgUP: failed getting track metadata: invalid status code from track metadata: 500" Sep 01 13:38:00 volumio volumio[867]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Sep 01 13:38:10 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:10 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:17 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 01 13:38:17 volumio volumio[867]: info: CURURI: music-library Sep 01 13:38:17 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:18 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 01 13:38:18 volumio volumio[867]: info: CURURI: music-library/NAS Sep 01 13:38:18 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:18 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 01 13:38:18 volumio volumio[867]: info: CURURI: music-library/NAS/Musik Sep 01 13:38:18 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:18 volumio volumio[867]: info: Preloading song: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:18 volumio volumio[867]: info: Preloading song: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:18 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 in service mpd Sep 01 13:38:18 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3' Sep 01 13:38:18 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/01 - Nothing Else Matters.mp3 in service mpd Sep 01 13:38:18 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/01 - Nothing Else Matters.mp3' Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Jul Sep 01 13:38:20 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Jul in service mpd Sep 01 13:38:20 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Jul' Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Pop Sep 01 13:38:20 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Pop in service mpd Sep 01 13:38:20 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Pop' Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Rock Sep 01 13:38:20 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Rock in service mpd Sep 01 13:38:20 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Rock' Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Svenskt Sep 01 13:38:20 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Svenskt in service mpd Sep 01 13:38:20 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Svenskt' Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Various Sep 01 13:38:20 volumio volumio[867]: info: Exploding uri music-library/NAS/Musik/Various in service mpd Sep 01 13:38:20 volumio volumio[867]: error: scanFolder - failure to stat '/mnt/NAS/Musik/Various' Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:20 volumio volumio[867]: info: Listing playlists Sep 01 13:38:20 volumio volumio[867]: info: Listing playlists Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Jul Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Jul Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Pop Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Pop Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Rock Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Rock Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Svenskt Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Svenskt Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Various Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Various Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:20 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Jul Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Jul Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Pop Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Pop Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Rock Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Rock Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Svenskt Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Svenskt Sep 01 13:38:20 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Various Sep 01 13:38:20 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Various Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:20 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:20 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:21 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:22 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:22 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:22 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Peps Persson Blodsband - Oh Boy!.mp3 Sep 01 13:38:22 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:22 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:22 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/01 - Nothing Else Matters.mp3 Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Jul Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Jul Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Pop Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Pop Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Rock Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Rock Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Svenskt Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Svenskt Sep 01 13:38:22 volumio volumio[867]: info: Adding Item to queue: music-library/NAS/Musik/Various Sep 01 13:38:22 volumio volumio[867]: info: Using cached record of: music-library/NAS/Musik/Various Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:22 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:22 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:22 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:28 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:28 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:30 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:30 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 13:38:33 volumio volumio[867]: info: Getting Alsa Cards List without I2S DAC Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 01 13:38:33 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 01 13:38:40 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:40 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:40 volumio volumio[867]: info: Listing playlists Sep 01 13:38:40 volumio volumio[867]: info: Listing playlists Sep 01 13:38:50 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:50 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:53 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:38:53 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:56 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:56 volumio volumio[867]: info: Preloading song: spotify:track:1nPIyLURZNqfCSRB3OphaV Sep 01 13:38:56 volumio volumio[867]: info: Exploding uri spotify:track:1nPIyLURZNqfCSRB3OphaV in service spop Sep 01 13:38:56 volumio volumio[867]: SPOTIFY: EXPLODING URI:spotify:track:1nPIyLURZNqfCSRB3OphaV Sep 01 13:38:56 volumio volumio[867]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1nPIyLURZNqfCSRB3OphaV","service":"spop","name":"Like Wooh Wooh","artist":"Rnbstylerz","album":"Hardstyle Party Bangers 2022","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b2737c5cc3f9aa554ee960459fdc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 01 13:38:59 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:59 volumio volumio[867]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::ClearQueue Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::clearPlayQueue Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:59 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::addQueueItems Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::addQueueItems Sep 01 13:38:59 volumio volumio[867]: info: Preload queue cleared Sep 01 13:38:59 volumio volumio[867]: info: Adding Item to queue: spotify:track:1nPIyLURZNqfCSRB3OphaV Sep 01 13:38:59 volumio volumio[867]: info: Using cached record of: spotify:track:1nPIyLURZNqfCSRB3OphaV Sep 01 13:38:59 volumio volumio[867]: info: CoreCommandRouter::volumioPushQueue Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::saveQueue Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::updateTrackBlock Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::getTrackBlock Sep 01 13:38:59 volumio volumio[867]: info: CoreCommandRouter::volumioPlay Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::play index 0 Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::stop Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::play index undefined Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:59 volumio volumio[867]: info: CoreStateMachine::startPlaybackTimer Sep 01 13:38:59 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:38:59 volumio volumio[867]: info: [1756733939416] ControllerSpotify::clearAddPlayTrack Sep 01 13:38:59 volumio volumio[867]: info: Sending Spotify command with payload to local API: /player/play Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=debug msg="resolved context of track" uri="spotify:track:1nPIyLURZNqfCSRB3OphaV" Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1nPIyLURZNqfCSRB3OphaV" Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1nPIyLURZNqfCSRB3OphaV" Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=trace msg="emitting websocket event: will_play" Sep 01 13:38:59 volumio volumio[867]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1nPIyLURZNqfCSRB3OphaV","play_origin":"go-librespot"}} Sep 01 13:38:59 volumio volumio[867]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1nPIyLURZNqfCSRB3OphaV","play_origin":"go-librespot"}} Sep 01 13:38:59 volumio go-librespot[29895]: time="2025-09-01T13:38:59Z" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1nPIyLURZNqfCSRB3OphaV: failed getting track metadata: invalid status code from track metadata: 500" Sep 01 13:38:59 volumio volumio[867]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Sep 01 13:39:00 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:39:00 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:39:00 volumio volumio[867]: info: Listing playlists Sep 01 13:39:00 volumio volumio[867]: info: Listing playlists Sep 01 13:39:01 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 01 13:39:01 volumio volumio[867]: info: CURURI: playlists Sep 01 13:39:01 volumio volumio[867]: info: Listing playlists Sep 01 13:39:01 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:02 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 01 13:39:02 volumio volumio[867]: info: CURURI: playlists/undefined Sep 01 13:39:02 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:04 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:04 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:05 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:06 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:06 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:06 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:07 volumio volumio[867]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/none.svg' Sep 01 13:39:07 volumio volumio[867]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/none.svg' Sep 01 13:39:09 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:10 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:10 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:10 volumio volumio[867]: info: CoreCommandRouter::volumioGetState Sep 01 13:39:10 volumio volumio[867]: info: CorePlayQueue::getTrack 0 Sep 01 13:39:10 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:14 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:15 volumio volumio[867]: info: Preload queue cleared Sep 01 13:39:16 volumio volumio[867]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 01 13:39:16 volumio volumio[867]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 13:39:16 volumio volumio[867]: TypeError: Cannot read property 'length' of undefined Sep 01 13:39:16 volumio volumio[867]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 01 13:39:16 volumio volumio[867]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 01 13:39:16 volumio volumio[867]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 01 13:39:16 volumio volumio[867]: at Parser.emit (events.js:315:20) Sep 01 13:39:16 volumio volumio[867]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 01 13:39:16 volumio volumio[867]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 01 13:39:16 volumio volumio[867]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 01 13:39:16 volumio volumio[867]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 01 13:39:16 volumio volumio[867]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 01 13:39:16 volumio volumio[867]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 01 13:39:16 volumio volumio[867]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 01 13:39:16 volumio volumio[867]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 01 13:39:16 volumio volumio[867]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 01 13:39:16 volumio volumio[867]: at IncomingMessage.emit (events.js:327:22) Sep 01 13:39:16 volumio volumio[867]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 01 13:39:16 volumio volumio[867]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 01 13:39:16 volumio volumio[867]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 13:39:16 volumio sudo[30199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-01 13:38 Sep 01 13:39:16 volumio sudo[30199]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:07:25 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3b9115b1943141a9d7186aa434f8f3c2"