Dec 12 08:39:05 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31:3000 from 192.168.0.14 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 12 08:39:05 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 12 08:39:05 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 12 08:39:05 volumio volumio[1234]: info: Discovery: Getting this device information Dec 12 08:39:05 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Dec 12 08:39:05 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:05 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 12 08:39:06 volumio volumio[1234]: verbose: New Socket.io Connection to 192.168.0.31 from 192.168.0.14 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Dec 12 08:39:06 volumio volumio[1234]: info: CoreCommandRouter::volumioGetState Dec 12 08:39:06 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:06 volumio volumio[1234]: info: CoreCommandRouter::volumioGetVisibleSources Dec 12 08:39:06 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 12 08:39:06 volumio volumio[1234]: info: CoreCommandRouter::volumioGetQueue Dec 12 08:39:06 volumio volumio[1234]: info: CoreStateMachine::getQueue Dec 12 08:39:06 volumio volumio[1234]: info: CorePlayQueue::getQueue Dec 12 08:39:06 volumio volumio[1234]: info: Listing playlists Dec 12 08:39:06 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: info: Retrieving Cloud Streaming UI Dec 12 08:39:11 volumio volumio[1234]: info: Getting Tidal Cloud Configuration Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: info: Getting Qobuz Cloud Configuration Dec 12 08:39:11 volumio volumio[1234]: info: Asking plugin for UI Config Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: info: Getting Spotify Cloud Configuration Dec 12 08:39:11 volumio volumio[1234]: info: Asking plugin for UI Config Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: info: Saving Spotify Acccount Dec 12 08:39:11 volumio volumio[1234]: info: Got Tidal Cloud Configuration Dec 12 08:39:11 volumio volumio[1234]: info: Got it Dec 12 08:39:11 volumio volumio[1234]: info: Got it Dec 12 08:39:11 volumio volumio[1234]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 12 08:39:11 volumio volumio[1234]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::volumioGetBrowseSources Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 12 08:39:11 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 12 08:39:12 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Dec 12 08:39:12 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand rescan Dec 12 08:39:12 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:12 volumio volumio[1234]: info: Dec 12 08:39:12 volumio volumio[1234]: ---------------------------- MPD announces state update: update Dec 12 08:39:12 volumio volumio[1234]: info: sendMpdCommand rescan took 7 milliseconds Dec 12 08:39:12 volumio volumio[1234]: info: ControllerMpd::getState Dec 12 08:39:12 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:12 volumio volumio[1234]: info: sendMpdCommand status took 5 milliseconds Dec 12 08:39:12 volumio volumio[1234]: info: sendMpdCommand status took 1 milliseconds Dec 12 08:39:12 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:14 volumio volumio[1234]: info: Command Router : Notfying DB Updatetrue Dec 12 08:39:14 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:14 volumio volumio[1234]: info: ControllerMpd::pushState Dec 12 08:39:14 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:14 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:14 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:14 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:14 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:14 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:14 volumio volumio[1234]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 12 08:39:14 volumio volumio[1234]: info: ------------------------------ 2029ms Dec 12 08:39:14 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:15 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 12 08:39:15 volumio volumio[1234]: info: CoreCommandRouter::Close All Modals sent Dec 12 08:39:16 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Dec 12 08:39:16 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand update Dec 12 08:39:16 volumio volumio[1234]: info: sendMpdCommand update took 3 milliseconds Dec 12 08:39:19 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 12 08:39:20 volumio volumio[1234]: info: MPD Database updated - AlbumList cache refreshed Dec 12 08:39:20 volumio volumio[1234]: info: Dec 12 08:39:20 volumio volumio[1234]: ---------------------------- MPD announces state update: database Dec 12 08:39:20 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:20 volumio volumio[1234]: info: Dec 12 08:39:20 volumio volumio[1234]: ---------------------------- MPD announces state update: update Dec 12 08:39:20 volumio volumio[1234]: info: ControllerMpd::getState Dec 12 08:39:20 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:20 volumio volumio[1234]: info: ControllerMpd::getState Dec 12 08:39:20 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:20 volumio volumio[1234]: info: sendMpdCommand status took 20 milliseconds Dec 12 08:39:20 volumio volumio[1234]: info: sendMpdCommand status took 19 milliseconds Dec 12 08:39:20 volumio volumio[1234]: info: sendMpdCommand status took 19 milliseconds Dec 12 08:39:20 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:23 volumio go-librespot[3248]: time="2025-12-12T08:39:23+07:00" level=trace msg="sent dealer ping" Dec 12 08:39:23 volumio go-librespot[3248]: time="2025-12-12T08:39:23+07:00" level=trace msg="received dealer pong" Dec 12 08:39:24 volumio volumio[1234]: info: Command Router : Notfying DB Updatetrue Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::Close All Modals sent Dec 12 08:39:24 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:24 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:24 volumio volumio[1234]: info: ControllerMpd::pushState Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:24 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:24 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:24 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:24 volumio volumio[1234]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 12 08:39:24 volumio volumio[1234]: info: ControllerMpd::pushState Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:24 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:24 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:24 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:24 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:24 volumio volumio[1234]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 12 08:39:24 volumio volumio[1234]: info: ------------------------------ 4745ms Dec 12 08:39:24 volumio volumio[1234]: info: ------------------------------ 4746ms Dec 12 08:39:24 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:24 volumio volumio[1234]: info: Dec 12 08:39:24 volumio volumio[1234]: ---------------------------- MPD announces state update: update Dec 12 08:39:24 volumio volumio[1234]: info: ControllerMpd::getState Dec 12 08:39:24 volumio volumio[1234]: verbose: ControllerMpd::sendMpdCommand status Dec 12 08:39:24 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:24 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:24 volumio volumio[1234]: info: sendMpdCommand status took 19 milliseconds Dec 12 08:39:24 volumio volumio[1234]: info: sendMpdCommand status took 19 milliseconds Dec 12 08:39:24 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:26 volumio volumio[1234]: info: Command Router : Notfying DB Updatefalse Dec 12 08:39:26 volumio volumio[1234]: info: CoreCommandRouter::Close All Modals sent Dec 12 08:39:26 volumio volumio[1234]: verbose: ControllerMpd::parseState Dec 12 08:39:26 volumio volumio[1234]: info: ControllerMpd::pushState Dec 12 08:39:26 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:26 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:26 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:26 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:26 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:26 volumio volumio[1234]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 12 08:39:26 volumio volumio[1234]: info: ------------------------------ 2124ms Dec 12 08:39:26 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 12 08:39:26 volumio volumio[1234]: info: CURURI: music-library Dec 12 08:39:26 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:26 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:28 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 12 08:39:28 volumio volumio[1234]: info: CURURI: music-library/INTERNAL Dec 12 08:39:28 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:30 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:30 volumio volumio[1234]: info: CorePlayQueue::getTrack 6 Dec 12 08:39:30 volumio volumio[1234]: info: Prefetching next song Dec 12 08:39:30 volumio volumio[1234]: info: [1765503570531] ControllerSpotify::prefetch Dec 12 08:39:30 volumio volumio[1234]: info: Sending Spotify command with payload to local API: /player/add_to_queue Dec 12 08:39:30 volumio go-librespot[3248]: time="2025-12-12T08:39:30+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:30 volumio go-librespot[3248]: time="2025-12-12T08:39:30+07:00" level=debug msg="prefetching next track" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:30 volumio go-librespot[3248]: time="2025-12-12T08:39:30+07:00" level=debug msg="selected format OGG_VORBIS_320 (021808e82927625b755f6f55d767573b03006d3d)" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:30 volumio go-librespot[3248]: time="2025-12-12T08:39:30+07:00" level=debug msg="requested aes key for file 021808e82927625b755f6f55d767573b03006d3d, gid: 5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:30 volumio go-librespot[3248]: time="2025-12-12T08:39:30+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:31 volumio go-librespot[3248]: time="2025-12-12T08:39:31+07:00" level=debug msg="fetched first chunk of 24, total size is 12196388 bytes" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:31 volumio go-librespot[3248]: time="2025-12-12T08:39:31+07:00" level=info msg="prefetched track \"Misty\" (duration: 356960ms)" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:31 volumio go-librespot[3248]: time="2025-12-12T08:39:31+07:00" level=debug msg="fetched chunk 1/23, size: 524288" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:31 volumio go-librespot[3248]: time="2025-12-12T08:39:31+07:00" level=debug msg="fetched chunk 2/23, size: 524288" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:31 volumio go-librespot[3248]: time="2025-12-12T08:39:31+07:00" level=debug msg="fetched chunk 3/23, size: 524288" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 12 08:39:33 volumio volumio[1234]: info: CURURI: music-library/INTERNAL/(10066-2-G) Amanda McBroom - Amanda[WAV] Dec 12 08:39:33 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=trace msg="emitting websocket event: not_playing" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:4JFDXuNsl7dZ3VfXwZDYoI","play_origin":"go-librespot"}} Dec 12 08:39:33 volumio volumio[1234]: error: Failed to decode event: not_playing Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:4JFDXuNsl7dZ3VfXwZDYoI","play_origin":"go-librespot"}} Dec 12 08:39:33 volumio volumio[1234]: error: Failed to decode event: not_playing Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=trace msg="emitting websocket event: will_play" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=info msg="loaded track \"Misty\" (paused: false, position: 0ms, duration: 356960ms, prefetched: true)" uri="spotify:track:5qauSfvYgvZK1rRb0jKmo9" Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","play_origin":"go-librespot"}} Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","play_origin":"go-librespot"}} Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=trace msg="scheduling prefetch in 327s" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=trace msg="emitting websocket event: metadata" Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","name":"Misty","artist_names":["Dianne Reeves"],"album_name":"The Best Of Dianne Reeves","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","position":0,"duration":356960,"release_date":"year:2002 month:1 day:1","track_number":12,"disc_number":1}} Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","name":"Misty","artist_names":["Dianne Reeves"],"album_name":"The Best Of Dianne Reeves","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","position":0,"duration":356960,"release_date":"year:2002 month:1 day:1","track_number":12,"disc_number":1}} Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:33 volumio go-librespot[3248]: time="2025-12-12T08:39:33+07:00" level=trace msg="emitting websocket event: playing" Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","resume":false,"play_origin":"go-librespot"}} Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: verbose: CURRENT POSITION 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:33 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","resume":false,"play_origin":"go-librespot"}} Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: verbose: CURRENT POSITION 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:33 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":1000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":1000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: verbose: CURRENT POSITION 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:33 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":1000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":1000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:33 volumio volumio[1234]: verbose: CURRENT POSITION 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:33 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:33 volumio volumio[1234]: info: CorePlayQueue::getTrack 5 Dec 12 08:39:33 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:33 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:35 volumio volumio[1234]: info: CoreStateMachine::startPlaybackTimer Dec 12 08:39:35 volumio volumio[1234]: info: CorePlayQueue::getTrack 6 Dec 12 08:39:35 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:35 volumio volumio[1234]: info: CorePlayQueue::getTrack 6 Dec 12 08:39:35 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:35 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:35 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:40 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:40 volumio volumio[1234]: info: Dec 12 08:39:40 volumio volumio[1234]: [1765503580023] ---------------------------- Client requests add and Play Volumio CUE entry Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Dec 12 08:39:40 volumio volumio[1234]: info: Adding CUE individual entry: 0 INTERNAL/(10066-2-G) Amanda McBroom - Amanda[WAV]/Amanda McBroom - Amanda.cue Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioAddQueueItems Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Dec 12 08:39:40 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:40 volumio volumio[1234]: info: Adding Item to queue: cue://INTERNAL/(10066-2-G) Amanda McBroom - Amanda[WAV]/Amanda McBroom - Amanda.cue@0 Dec 12 08:39:40 volumio volumio[1234]: info: Exploding uri cue://INTERNAL/(10066-2-G) Amanda McBroom - Amanda[WAV]/Amanda McBroom - Amanda.cue@0 in service mpd Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::play index 150 Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::stop Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 6 Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::serviceStop Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 6 Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::serviceStop Dec 12 08:39:40 volumio volumio[1234]: info: Spotify Stop Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: SPOTIFY STOP Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: {"status":"play","position":6,"title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d0000b273adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","codec":"ogg","seek":500,"duration":356,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":72,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 12 08:39:40 volumio volumio[1234]: info: Sending Spotify command to local API: /player/pause Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::play index undefined Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 150 Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::saveQueue Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:40 volumio go-librespot[3248]: time="2025-12-12T08:39:40+07:00" level=debug msg="pause track at 6470ms" Dec 12 08:39:40 volumio go-librespot[3248]: time="2025-12-12T08:39:40+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:40 volumio go-librespot[3248]: time="2025-12-12T08:39:40+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:40 volumio go-librespot[3248]: time="2025-12-12T08:39:40+07:00" level=trace msg="emitting websocket event: paused" Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","play_origin":"go-librespot"}} Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":7000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:40 volumio volumio[1234]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":7000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:40 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::syncState stateService pause Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","play_origin":"go-librespot"}} Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":7000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:40 volumio volumio[1234]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Misty","artist":"Dianne Reeves","album":"The Best Of Dianne Reeves","albumart":"https://i.scdn.co/image/ab67616d00001e02adf1a14cc4ef41c0ad265069","uri":"spotify:track:5qauSfvYgvZK1rRb0jKmo9","trackType":"spotify","seek":7000,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:40 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::syncState stateService pause Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Dec 12 08:39:40 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:40 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:40 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:40 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::play index undefined Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::startPlaybackTimer Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: info: [1765503587235] ControllerSpotify::clearAddPlayTrack Dec 12 08:39:47 volumio volumio[1234]: info: Sending Spotify command with payload to local API: /player/play Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="resolved context of track" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="emitting websocket event: will_play" Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","play_origin":"go-librespot"}} Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","play_origin":"go-librespot"}} Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="selected format OGG_VORBIS_320 (87e3fc35bb43c9b26adcebddcbf1157e0c425f70)" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="requested aes key for file 87e3fc35bb43c9b26adcebddcbf1157e0c425f70, gid: 0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="fetched first chunk of 13, total size is 6710788 bytes" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=info msg="loaded track \"Lonely Waltz\" (paused: false, position: 0ms, duration: 194973ms, prefetched: false)" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="scheduling prefetch in 165s" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="emitting websocket event: metadata" Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","name":"Lonely Waltz","artist_names":["Frans Bak","Sinne Eeg"],"album_name":"Lonely Waltz","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","position":0,"duration":194973,"release_date":"year:2024 month:3 day:1","track_number":1,"disc_number":1}} Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","name":"Lonely Waltz","artist_names":["Frans Bak","Sinne Eeg"],"album_name":"Lonely Waltz","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","position":0,"duration":194973,"release_date":"year:2024 month:3 day:1","track_number":1,"disc_number":1}} Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:47 volumio go-librespot[3248]: time="2025-12-12T08:39:47+07:00" level=trace msg="emitting websocket event: playing" Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","resume":false,"play_origin":"go-librespot"}} Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:47 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","resume":false,"play_origin":"go-librespot"}} Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:47 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:47 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:47 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:47 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:47 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:47 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:48 volumio go-librespot[3248]: time="2025-12-12T08:39:48+07:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:0LuPh38D2jW4IFgPYwcUXn" Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:49 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:49 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":0,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:49 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::syncState stateService play Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus play Dec 12 08:39:49 volumio volumio[1234]: info: Received an update from plugin. extracting info from payload Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:49 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:49 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:49 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:49 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:52 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 12 08:39:52 volumio volumio[1234]: info: CURURI: music-library/INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV] Dec 12 08:39:53 volumio go-librespot[3248]: time="2025-12-12T08:39:53+07:00" level=trace msg="sent dealer ping" Dec 12 08:39:53 volumio go-librespot[3248]: time="2025-12-12T08:39:53+07:00" level=trace msg="received dealer pong" Dec 12 08:39:54 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:55 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:55 volumio volumio[1234]: info: Dec 12 08:39:55 volumio volumio[1234]: [1765503595239] ---------------------------- Client requests add and Play Volumio CUE entry Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Dec 12 08:39:55 volumio volumio[1234]: info: Adding CUE individual entry: 0 INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioAddQueueItems Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Dec 12 08:39:55 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:39:55 volumio volumio[1234]: info: Adding Item to queue: cue://INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue@0 Dec 12 08:39:55 volumio volumio[1234]: info: Exploding uri cue://INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue@0 in service mpd Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::play index 151 Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::stop Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::stPlaybackTimer Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::serviceStop Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::serviceStop Dec 12 08:39:55 volumio volumio[1234]: info: Spotify Stop Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: SPOTIFY STOP Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: {"status":"play","position":0,"title":"Lonely Waltz","artist":"Frans Bak","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d0000b2736eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","codec":"ogg","seek":0,"duration":194,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":72,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 12 08:39:55 volumio volumio[1234]: info: Sending Spotify command to local API: /player/pause Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::play index undefined Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 151 Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::saveQueue Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:55 volumio go-librespot[3248]: time="2025-12-12T08:39:55+07:00" level=debug msg="pause track at 7578ms" Dec 12 08:39:55 volumio go-librespot[3248]: time="2025-12-12T08:39:55+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:55 volumio go-librespot[3248]: time="2025-12-12T08:39:55+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 12 08:39:55 volumio go-librespot[3248]: time="2025-12-12T08:39:55+07:00" level=trace msg="emitting websocket event: paused" Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","play_origin":"go-librespot"}} Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":6000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":6000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:55 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::syncState stateService pause Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","play_origin":"go-librespot"}} Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: PUSH STATE SPOTIFY Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: {"status":"pause","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":6000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::servicePushState Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Lonely Waltz","artist":"Frans Bak, Sinne Eeg","album":"Lonely Waltz","albumart":"https://i.scdn.co/image/ab67616d00001e026eb9ce8ee14724dfcf03c94f","uri":"spotify:track:0LuPh38D2jW4IFgPYwcUXn","trackType":"spotify","seek":6000,"duration":194,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 12 08:39:55 volumio volumio[1234]: verbose: CURRENT POSITION 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::syncState stateService pause Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::syncState currentStatus stop Dec 12 08:39:55 volumio volumio[1234]: info: CoreStateMachine::pushState Dec 12 08:39:55 volumio volumio[1234]: info: CorePlayQueue::getTrack 0 Dec 12 08:39:55 volumio volumio[1234]: info: CoreCommandRouter::volumioPushState Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:55 volumio volumio[1234]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Dec 12 08:39:56 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 12 08:39:58 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 12 08:39:58 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 12 08:40:01 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:40:01 volumio volumio[1234]: info: Dec 12 08:40:01 volumio volumio[1234]: [1765503601634] ---------------------------- Client requests add and Play Volumio CUE entry Dec 12 08:40:01 volumio volumio[1234]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Dec 12 08:40:01 volumio volumio[1234]: info: Adding CUE individual entry: 0 INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue Dec 12 08:40:01 volumio volumio[1234]: info: CoreCommandRouter::volumioAddQueueItems Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Dec 12 08:40:01 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Dec 12 08:40:01 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:40:01 volumio volumio[1234]: info: Adding Item to queue: cue://INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue@0 Dec 12 08:40:01 volumio volumio[1234]: info: Exploding uri cue://INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue@0 in service mpd Dec 12 08:40:01 volumio volumio[1234]: info: CoreCommandRouter::volumioPlay Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::play index 152 Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::stop Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::play index undefined Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:40:01 volumio volumio[1234]: info: CorePlayQueue::getTrack 152 Dec 12 08:40:01 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Dec 12 08:40:01 volumio volumio[1234]: info: CorePlayQueue::saveQueue Dec 12 08:40:01 volumio volumio[1234]: info: CoreStateMachine::updateTrackBlock Dec 12 08:40:01 volumio volumio[1234]: info: CorePlayQueue::getTrackBlock Dec 12 08:40:09 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:40:09 volumio volumio[1234]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 12 08:40:09 volumio volumio[1234]: info: CoreStateMachine::ClearQueue Dec 12 08:40:09 volumio volumio[1234]: info: CoreStateMachine::stop Dec 12 08:40:09 volumio volumio[1234]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 12 08:40:09 volumio volumio[1234]: info: CorePlayQueue::clearPlayQueue Dec 12 08:40:09 volumio volumio[1234]: info: CorePlayQueue::saveQueue Dec 12 08:40:09 volumio volumio[1234]: info: CoreCommandRouter::volumioPushQueue Dec 12 08:40:09 volumio volumio[1234]: info: CoreStateMachine::addQueueItems Dec 12 08:40:09 volumio volumio[1234]: info: CorePlayQueue::addQueueItems Dec 12 08:40:09 volumio volumio[1234]: info: Preload queue cleared Dec 12 08:40:09 volumio volumio[1234]: info: Adding Item to queue: music-library/INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV] Dec 12 08:40:09 volumio volumio[1234]: info: Exploding uri music-library/INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV] in service mpd Dec 12 08:40:09 volumio volumio[1234]: info: ALBUMART /albumart?cacheid=464&web=Pat%20Coil/Schemes%20And%20Dreams/extralarge&path=%2Fmnt%2FINTERNAL%2F(10042-2-F)%20Pat%20Coil%20-%20Schemes%20And%20Dreams%20(1994)%5BWAV%5D%2FPat%20Coil%20-%20Schemes%20And%20Dreams.cue&metadata=false Dec 12 08:40:09 volumio volumio[1234]: info: URI /mnt/INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue Dec 12 08:40:09 volumio volumio[1234]: info: ALBUMART /albumart?cacheid=464&web=Pat%20Coil/Schemes%20And%20Dreams/extralarge&path=%2Fmnt%2FINTERNAL%2F(10042-2-F)%20Pat%20Coil%20-%20Schemes%20And%20Dreams%20(1994)%5BWAV%5D%2FPat%20Coil%20-%20Schemes%20And%20Dreams.cue&metadata=false Dec 12 08:40:09 volumio volumio[1234]: info: URI /mnt/INTERNAL/(10042-2-F) Pat Coil - Schemes And Dreams (1994)[WAV]/Pat Coil - Schemes And Dreams.cue Dec 12 08:40:09 volumio volumio[1234]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 08:40:09 volumio volumio[1234]: Error: Unable to resolve or reject the same promise twice Dec 12 08:40:09 volumio volumio[1234]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 12 08:40:09 volumio volumio[1234]: at /volumio/app/plugins/music_service/mpd/index.js:2587:21 Dec 12 08:40:09 volumio volumio[1234]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Dec 12 08:40:09 volumio volumio[1234]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Dec 12 08:40:09 volumio volumio[1234]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Dec 12 08:40:09 volumio volumio[1234]: at Socket.emit (node:events:514:28) Dec 12 08:40:09 volumio volumio[1234]: at addChunk (node:internal/streams/readable:343:12) Dec 12 08:40:09 volumio volumio[1234]: at readableAddChunk (node:internal/streams/readable:312:11) Dec 12 08:40:09 volumio volumio[1234]: at Readable.push (node:internal/streams/readable:253:10) Dec 12 08:40:09 volumio volumio[1234]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Dec 12 08:40:09 volumio volumio[1234]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 12 08:40:10 volumio sudo[6349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-12 08:39' Dec 12 08:40:10 volumio sudo[6349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"