-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Sun 2025-05-11 12:18:53 CST. -- May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::volumioGetBrowseSources May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:17:01 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 11 12:17:01 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:02 volumio volumio[10103]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 11 12:17:02 volumio volumio[10103]: info: Completed starting MyVolumio Plugin May 11 12:17:02 volumio volumio[10103]: [Metrics] CommandRouter: 34s 385.93ms May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::volumiosetStartupVolume May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:02 volumio volumio[10103]: info: VolumeController:: Setting startup Volume 90 May 11 12:17:02 volumio volumio[10103]: info: VolumeController::SetAlsaVolume90 May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::Close All Modals sent May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::Close All Modals sent May 11 12:17:02 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:02 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:02 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:02 volumio volumio[10103]: SPOTIFY: SPOTIFY VOLUME 93 May 11 12:17:02 volumio volumio[10103]: SPOTIFY: VOLUMIO VOLUME 90 May 11 12:17:02 volumio volumio[10103]: SPOTIFY: DELTA VOLUME ENOUGH: true May 11 12:17:02 volumio volumio[10103]: info: Setting Spotify Volume from Volumio: 90 May 11 12:17:02 volumio volumio-remote-updater[589]: No test mode May 11 12:17:02 volumio volumio-remote-updater[589]: No alpha test mode May 11 12:17:02 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 11 12:17:02 volumio volumio[10103]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav May 11 12:17:02 volumio volumio[10103]: aplay: main:828: audio open error: Device or resource busy May 11 12:17:03 volumio volumio[10103]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 11 12:17:03 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 11 12:17:03 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 11 12:17:03 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 11 12:17:03 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 11 12:17:03 volumio go-librespot[10274]: time="2025-05-11T12:17:03+08:00" level=trace msg="sent dealer ping" May 11 12:17:03 volumio go-librespot[10274]: time="2025-05-11T12:17:03+08:00" level=trace msg="received dealer pong" May 11 12:17:03 volumio volumio[10103]: SPOTIFY: SETTING SPOTIFY VOLUME 90 May 11 12:17:03 volumio volumio[10103]: info: Sending Spotify command with payload to local API: /player/volume May 11 12:17:03 volumio go-librespot[10274]: time="2025-05-11T12:17:03+08:00" level=debug msg="update volume to 58981/65535" May 11 12:17:04 volumio go-librespot[10274]: time="2025-05-11T12:17:04+08:00" level=debug msg="put connect state because VOLUME_CHANGED" May 11 12:17:04 volumio go-librespot[10274]: time="2025-05-11T12:17:04+08:00" level=trace msg="emitting websocket event: volume" May 11 12:17:04 volumio volumio[10103]: SPOTIFY: received: {"type":"volume","data":{"value":90,"max":100}} May 11 12:17:04 volumio volumio[10103]: SPOTIFY: RECEIVED SPOTIFY VOLUME 90 May 11 12:17:09 volumio volumio[10103]: info: BOOT COMPLETED May 11 12:17:16 volumio volumio[10103]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 11 12:17:16 volumio sudo[10484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 12:17:16 volumio sudo[10484]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:16 volumio sudo[10484]: pam_unix(sudo:session): session closed for user root May 11 12:17:16 volumio volumio[10103]: info: MPD Permissions set May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:16 volumio sudo[10487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 12:17:16 volumio sudo[10487]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:16 volumio systemd[1]: Stopping Music Player Daemon... May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:17:16 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:16 volumio systemd[1]: mpd.service: Succeeded. May 11 12:17:16 volumio systemd[1]: Stopped Music Player Daemon. May 11 12:17:16 volumio systemd[1]: Starting Music Player Daemon... May 11 12:17:16 volumio sudo[10493]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 12:17:16 volumio sudo[10493]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:16 volumio sudo[10493]: pam_unix(sudo:session): session closed for user root May 11 12:17:17 volumio mpd[10496]: May 11 12:17 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 12:17:17 volumio systemd[1]: Started Music Player Daemon. May 11 12:17:17 volumio sudo[10487]: pam_unix(sudo:session): session closed for user root May 11 12:17:17 volumio volumio[10103]: error: updateQueue error: null May 11 12:17:17 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:23 volumio volumio[10103]: info: CoreCommandRouter::volumioNext May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::next May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::stop May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::stPlaybackTimer May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::updateTrackBlock May 11 12:17:23 volumio volumio[10103]: info: CorePlayQueue::getTrackBlock May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:23 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:23 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:17:23 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::serviceStop May 11 12:17:23 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:23 volumio volumio[10103]: info: CoreCommandRouter::serviceStop May 11 12:17:23 volumio volumio[10103]: info: ControllerMpd::stop May 11 12:17:23 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand stop May 11 12:17:23 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:23 volumio volumio[10103]: info: sendMpdCommand stop took 5 milliseconds May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::play index undefined May 11 12:17:23 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:23 volumio volumio[10103]: info: CorePlayQueue::getTrack 1 May 11 12:17:24 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::volumioPlay May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::play index undefined May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::startPlaybackTimer May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::clearAddPlayTracks USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3 May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand stop May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand stop took 1 milliseconds May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand clear May 11 12:17:24 volumio volumio[10103]: info: May 11 12:17:24 volumio volumio[10103]: ---------------------------- MPD announces system playlist update May 11 12:17:24 volumio volumio[10103]: info: Ignoring MPD Status Update May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand clear took 1 milliseconds May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand add "USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3" May 11 12:17:24 volumio volumio[10103]: error: updateQueue error: null May 11 12:17:24 volumio volumio[10103]: info: May 11 12:17:24 volumio volumio[10103]: ---------------------------- MPD announces system playlist update May 11 12:17:24 volumio volumio[10103]: info: Ignoring MPD Status Update May 11 12:17:24 volumio volumio[10103]: info: ------------------------------ 2ms May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand add "USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3" took 1 milliseconds May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand play May 11 12:17:24 volumio volumio[10103]: info: ------------------------------ 2ms May 11 12:17:24 volumio volumio[10103]: info: May 11 12:17:24 volumio volumio[10103]: ---------------------------- MPD announces state update: player May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand play took 4 milliseconds May 11 12:17:24 volumio volumio[10103]: info: ControllerMpd::getState May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand status May 11 12:17:24 volumio volumio[10103]: info: May 11 12:17:24 volumio volumio[10103]: ---------------------------- MPD announces state update: player May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand status took 40 milliseconds May 11 12:17:24 volumio volumio[10103]: info: ControllerMpd::getState May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand status May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::parseState May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand status took 2 milliseconds May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand playlistinfo took 2 milliseconds May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::parseState May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::parseTrackInfo May 11 12:17:24 volumio volumio[10103]: info: ControllerMpd::pushState May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"잠은 안오고 배는 고프고 (失眠又饥饿)","artist":"Nine Muses","album":"LOST","uri":"USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3","trackType":"mp3"} May 11 12:17:24 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus stop May 11 12:17:24 volumio volumio[10103]: info: ------------------------------ 47ms May 11 12:17:24 volumio volumio[10103]: info: sendMpdCommand playlistinfo took 3 milliseconds May 11 12:17:24 volumio volumio[10103]: verbose: ControllerMpd::parseTrackInfo May 11 12:17:24 volumio volumio[10103]: info: ControllerMpd::pushState May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80,"duration":205,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"잠은 안오고 배는 고프고 (失眠又饥饿)","artist":"Nine Muses","album":"LOST","uri":"USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3","trackType":"mp3"} May 11 12:17:24 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus play May 11 12:17:24 volumio volumio[10103]: info: Received an update from plugin. extracting info from payload May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:24 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:24 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:24 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:24 volumio volumio[10103]: info: ------------------------------ 27ms May 11 12:17:24 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:24 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:31 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:33 volumio go-librespot[10274]: time="2025-05-11T12:17:33+08:00" level=trace msg="sent dealer ping" May 11 12:17:33 volumio go-librespot[10274]: time="2025-05-11T12:17:33+08:00" level=trace msg="received dealer pong" May 11 12:17:34 volumio volumio[10103]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 11 12:17:34 volumio sudo[10537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 12:17:34 volumio sudo[10537]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:34 volumio sudo[10537]: pam_unix(sudo:session): session closed for user root May 11 12:17:34 volumio volumio[10103]: info: MPD Permissions set May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:34 volumio sudo[10540]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:34 volumio sudo[10540]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:34 volumio systemd[1]: Stopping Music Player Daemon... May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:17:34 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:17:34 volumio systemd[1]: mpd.service: Succeeded. May 11 12:17:34 volumio systemd[1]: Stopped Music Player Daemon. May 11 12:17:34 volumio systemd[1]: Starting Music Player Daemon... May 11 12:17:34 volumio sudo[10546]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 12:17:34 volumio sudo[10546]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:17:34 volumio sudo[10546]: pam_unix(sudo:session): session closed for user root May 11 12:17:35 volumio mpd[10548]: May 11 12:17 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 12:17:35 volumio systemd[1]: Started Music Player Daemon. May 11 12:17:35 volumio sudo[10540]: pam_unix(sudo:session): session closed for user root May 11 12:17:35 volumio volumio[10103]: error: updateQueue error: null May 11 12:17:37 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:41 volumio volumio[10103]: info: CoreCommandRouter::volumioNext May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::next May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::stop May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::stPlaybackTimer May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::updateTrackBlock May 11 12:17:41 volumio volumio[10103]: info: CorePlayQueue::getTrackBlock May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:41 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:41 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:17:41 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::serviceStop May 11 12:17:41 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:41 volumio volumio[10103]: info: CoreCommandRouter::serviceStop May 11 12:17:41 volumio volumio[10103]: info: ControllerMpd::stop May 11 12:17:41 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand stop May 11 12:17:41 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:41 volumio volumio[10103]: info: sendMpdCommand stop took 8 milliseconds May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::play index undefined May 11 12:17:41 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:41 volumio volumio[10103]: info: CorePlayQueue::getTrack 1 May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::volumioPlay May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::play index undefined May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::startPlaybackTimer May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::clearAddPlayTracks USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3 May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand stop May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand stop took 0 milliseconds May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand clear May 11 12:17:42 volumio volumio[10103]: info: May 11 12:17:42 volumio volumio[10103]: ---------------------------- MPD announces system playlist update May 11 12:17:42 volumio volumio[10103]: info: Ignoring MPD Status Update May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand clear took 1 milliseconds May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand add "USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3" May 11 12:17:42 volumio volumio[10103]: error: updateQueue error: null May 11 12:17:42 volumio volumio[10103]: info: May 11 12:17:42 volumio volumio[10103]: ---------------------------- MPD announces system playlist update May 11 12:17:42 volumio volumio[10103]: info: Ignoring MPD Status Update May 11 12:17:42 volumio volumio[10103]: info: ------------------------------ 3ms May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand add "USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3" took 2 milliseconds May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand play May 11 12:17:42 volumio volumio[10103]: info: ------------------------------ 2ms May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand play took 2 milliseconds May 11 12:17:42 volumio volumio[10103]: info: May 11 12:17:42 volumio volumio[10103]: ---------------------------- MPD announces state update: player May 11 12:17:42 volumio volumio[10103]: info: ControllerMpd::getState May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand status May 11 12:17:42 volumio volumio[10103]: info: May 11 12:17:42 volumio volumio[10103]: ---------------------------- MPD announces state update: player May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand status took 39 milliseconds May 11 12:17:42 volumio volumio[10103]: info: ControllerMpd::getState May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand status May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::parseState May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand status took 2 milliseconds May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand playlistinfo took 1 milliseconds May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::parseState May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::parseTrackInfo May 11 12:17:42 volumio volumio[10103]: info: ControllerMpd::pushState May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":205,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"잠은 안오고 배는 고프고 (失眠又饥饿)","artist":"Nine Muses","album":"LOST","uri":"USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3","trackType":"mp3"} May 11 12:17:42 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus stop May 11 12:17:42 volumio volumio[10103]: info: ------------------------------ 46ms May 11 12:17:42 volumio volumio[10103]: info: sendMpdCommand playlistinfo took 3 milliseconds May 11 12:17:42 volumio volumio[10103]: verbose: ControllerMpd::parseTrackInfo May 11 12:17:42 volumio volumio[10103]: info: ControllerMpd::pushState May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","position":0,"seek":125,"duration":205,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"잠은 안오고 배는 고프고 (失眠又饥饿)","artist":"Nine Muses","album":"LOST","uri":"USB/B88F-9FE0/16.韩语经典歌曲/Nine Muses - 잠은 안오고 배는 고프고 (失眠又饥饿).mp3","trackType":"mp3"} May 11 12:17:42 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus play May 11 12:17:42 volumio volumio[10103]: info: Received an update from plugin. extracting info from payload May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:42 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:17:42 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:17:42 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:17:42 volumio volumio[10103]: info: ------------------------------ 25ms May 11 12:17:42 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:42 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:17:44 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:51 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:17:58 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:03 volumio go-librespot[10274]: time="2025-05-11T12:18:03+08:00" level=trace msg="sent dealer ping" May 11 12:18:03 volumio go-librespot[10274]: time="2025-05-11T12:18:03+08:00" level=trace msg="received dealer pong" May 11 12:18:05 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:11 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:13 volumio volumio[10103]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] May 11 12:18:13 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions May 11 12:18:13 volumio sudo[10656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 12:18:13 volumio sudo[10656]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:13 volumio sudo[10656]: pam_unix(sudo:session): session closed for user root May 11 12:18:13 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:13 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:13 volumio sudo[10659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 12:18:13 volumio sudo[10659]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:13 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:18:13 volumio systemd[1]: Stopping Music Player Daemon... May 11 12:18:13 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:13 volumio volumio[10103]: info: MPD Permissions set May 11 12:18:13 volumio systemd[1]: mpd.service: Succeeded. May 11 12:18:13 volumio systemd[1]: Stopped Music Player Daemon. May 11 12:18:13 volumio systemd[1]: Starting Music Player Daemon... May 11 12:18:13 volumio sudo[10665]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 12:18:13 volumio sudo[10665]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:13 volumio sudo[10665]: pam_unix(sudo:session): session closed for user root May 11 12:18:14 volumio mpd[10667]: May 11 12:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 12:18:14 volumio systemd[1]: Started Music Player Daemon. May 11 12:18:14 volumio sudo[10659]: pam_unix(sudo:session): session closed for user root May 11 12:18:14 volumio volumio[10103]: error: updateQueue error: null May 11 12:18:18 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:25 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:26 volumio volumio[10103]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions May 11 12:18:26 volumio sudo[10689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 12:18:26 volumio sudo[10689]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio sudo[10689]: pam_unix(sudo:session): session closed for user root May 11 12:18:26 volumio sudo[10691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 12:18:26 volumio sudo[10691]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 12:18:26 volumio volumio[10103]: info: MPD Permissions set May 11 12:18:26 volumio systemd[1]: Stopping Music Player Daemon... May 11 12:18:26 volumio systemd[1]: mpd.service: Succeeded. May 11 12:18:26 volumio systemd[1]: Stopped Music Player Daemon. May 11 12:18:26 volumio systemd[1]: Starting Music Player Daemon... May 11 12:18:26 volumio sudo[10698]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 11 12:18:26 volumio sudo[10698]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 12:18:26 volumio sudo[10698]: pam_unix(sudo:session): session closed for user root May 11 12:18:27 volumio mpd[10700]: May 11 12:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 12:18:27 volumio systemd[1]: Started Music Player Daemon. May 11 12:18:27 volumio sudo[10691]: pam_unix(sudo:session): session closed for user root May 11 12:18:27 volumio volumio[10103]: error: updateQueue error: null May 11 12:18:32 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:33 volumio go-librespot[10274]: time="2025-05-11T12:18:33+08:00" level=trace msg="received accesspoint ping" May 11 12:18:33 volumio go-librespot[10274]: time="2025-05-11T12:18:33+08:00" level=trace msg="received accesspoint pong ack" May 11 12:18:33 volumio go-librespot[10274]: time="2025-05-11T12:18:33+08:00" level=trace msg="sent dealer ping" May 11 12:18:33 volumio go-librespot[10274]: time="2025-05-11T12:18:33+08:00" level=trace msg="received dealer pong" May 11 12:18:33 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 11 12:18:33 volumio volumio[10103]: info: In handleBrowseUri, curUri=spotify May 11 12:18:33 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:33 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:33 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:33 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:38 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:41 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 11 12:18:41 volumio volumio[10103]: info: In handleBrowseUri, curUri=spotify:playlist:37i9dQZF1DXdzMu6LHKCwj May 11 12:18:41 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6vw9OTw8rBhatDSdlxVIuF May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0ti0CEUPplsI7AZDyexrXy May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4SinziOMDPR58wWHakWP9v May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:3wBeIjb0vtiTwIQPce2stZ May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0fK7ie6XwGxQTIkpFoWkd1 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2nopDUxom21JoMzFXj9wS0 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2BoGqSfsf9z5T1exqHtW54 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:7kb6IV0z8Nd7vejSdAq0YN May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5doooVlMVRZztQbySqARMI May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2gu6fOPHZVG0GzjCvnxlBA May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0IjaSeBp6SHXTELm4C9ifk May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1z5ebC9238uGoBgzYyvGpQ May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:3H1ikRF1DLYkI8CHr5J7cy May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:3gJAFFELdZyIM8tiwLAikg May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4Vpl8DJahXjdFHpEoZ8W11 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:406IpEtZPvbxApWTGM3twY May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5r3nfTCyrc3KzNexD5pXyU May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0GOqhXyouUxqPEw9ypTOLm May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:7C9YOYpERtlL1kRfiS4LMf May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1Ah8dQEPYpmtl7FRvXJOOU May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:3YYJhvip3QCfKirhcLVJUf May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1lcBt7LoEikqYmhUoa2cez May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1j15Ar0qGDzIR0v3CQv3JL May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5yfhzEct1ulyU6g5oVRraj May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:17WnCJhdwQxOIiBZBkYocN May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4qzV2qURSJBVV9d7BkMx4g May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5Fhr3wqeieN5WDkAsqL1JJ May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:68UrZQUuO3O6eUiD226xHg May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1yX9gy5fK02j6nBnGJ1S3k May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4CPuDVC8jhhK6lA2DIt8Cf May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5PclMa9Pxs1OFWSAS6Nid9 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6vBVBzf0VeRO4aPwABnohX May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6XtNw289lraKPESASgB5Hj May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6HSns0qPQQfgekCrBF0Dkf May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:49oOgXKqm6xTavBtekzVHg May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:5zQUndaoBtXJ10SsApqtvw May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6efcMTYO2lJ0zcpQEPk8m1 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:7GOIrZTegzVty8mhNhRuA0 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:7G7mSV4BebkoHWwKTDvXu9 May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0mXXjVVAhaasNXga2HMgJK May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:1Y3Z8ZgjFse47Nt2ZR4EFU May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4irSoWVMefjnL4ZjmmM25t May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0WfGe9wV6Dz8ygraMCI7wU May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2YUUYGB1kMtXKTQ6ajAjTA May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:3YNjvUXgfQznx5IZHAXk6i May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:0ofqcEBPdlyczRjUhjCiIS May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2p1sYugVQs0H8XZemnRrIK May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:4rBRRLgdB9DYJhqA9uVcWt May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:2DaEOAKYadUMO7x0CsobRU May 11 12:18:41 volumio volumio[10103]: info: Preloading song: spotify:track:6AvxOYstG9cCD4RVQp4aJz May 11 12:18:41 volumio volumio[10103]: info: Exploding uri spotify:track:6vw9OTw8rBhatDSdlxVIuF in service spop May 11 12:18:41 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:6vw9OTw8rBhatDSdlxVIuF May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:0ti0CEUPplsI7AZDyexrXy in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:0ti0CEUPplsI7AZDyexrXy May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:4SinziOMDPR58wWHakWP9v in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:4SinziOMDPR58wWHakWP9v May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:3wBeIjb0vtiTwIQPce2stZ in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:3wBeIjb0vtiTwIQPce2stZ May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","service":"spop","name":"Pookie","artist":"FIFTY FIFTY","album":"Day & Night","type":"song","duration":152,"albumart":"https://i.scdn.co/image/ab67616d0000b273b878e64f5e7830e50a3f765d","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0ti0CEUPplsI7AZDyexrXy","service":"spop","name":"Countdown!","artist":"TWS","album":"TWS 3rd Mini Album 'TRY WITH US'","type":"song","duration":150,"albumart":"https://i.scdn.co/image/ab67616d0000b273af702dd0fadbdf36ea1642a4","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:0fK7ie6XwGxQTIkpFoWkd1 in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:0fK7ie6XwGxQTIkpFoWkd1 May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4SinziOMDPR58wWHakWP9v","service":"spop","name":"Good Day 2025 (Telepathy + By the Moonlight Window)","artist":"G-DRAGON","album":"Good Day 2025 (Telepathy + By the Moonlight Window)","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b27372c6dacbc5d13fe29cc2a23c","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:2nopDUxom21JoMzFXj9wS0 in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:2nopDUxom21JoMzFXj9wS0 May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0fK7ie6XwGxQTIkpFoWkd1","service":"spop","name":"like JENNIE","artist":"JENNIE","album":"Ruby","type":"song","duration":123,"albumart":"https://i.scdn.co/image/ab67616d0000b2735a43918ea90bf1e44b7bdcfd","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:2BoGqSfsf9z5T1exqHtW54 in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:2BoGqSfsf9z5T1exqHtW54 May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3wBeIjb0vtiTwIQPce2stZ","service":"spop","name":"Love Language","artist":"TOMORROW X TOGETHER","album":"Love Language","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b273bc23afc74585dc9ea1ae22c3","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2nopDUxom21JoMzFXj9wS0","service":"spop","name":"HANDS UP","artist":"MEOVV","album":"HANDS UP","type":"song","duration":192,"albumart":"https://i.scdn.co/image/ab67616d0000b273dda097a10d432db726d6f283","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:7kb6IV0z8Nd7vejSdAq0YN in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:7kb6IV0z8Nd7vejSdAq0YN May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2BoGqSfsf9z5T1exqHtW54","service":"spop","name":"Wait On Me","artist":"KAI","album":"Wait On Me - The 4th Mini Album","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b273f3babe94ff2dd2ae249a28e9","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:5doooVlMVRZztQbySqARMI in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:5doooVlMVRZztQbySqARMI May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7kb6IV0z8Nd7vejSdAq0YN","service":"spop","name":"Stop The Rain (TABLO X RM)","artist":"TABLO","album":"Stop The Rain (TABLO X RM)","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b2731b66776ed69c89c8d20dc060","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:2gu6fOPHZVG0GzjCvnxlBA in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:2gu6fOPHZVG0GzjCvnxlBA May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:0IjaSeBp6SHXTELm4C9ifk in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:0IjaSeBp6SHXTELm4C9ifk May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5doooVlMVRZztQbySqARMI","service":"spop","name":"HOME SWEET HOME (feat. TAEYANG & DAESUNG)","artist":"G-DRAGON","album":"Übermensch","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b273e1b8e368ceafe1117e846859","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:1z5ebC9238uGoBgzYyvGpQ in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:1z5ebC9238uGoBgzYyvGpQ May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2gu6fOPHZVG0GzjCvnxlBA","service":"spop","name":"Moon(with VIVIZ, MINHYUK, KIHYUN, I.M of MONSTA X, HOSHI, WONWOO, MINGYU, DK, SEUNGKWAN of SEVENTEEN, HELLO GLOOM, ROCKY, CHOI YOOJUNG, KIM DOYEON, CHA NI (SF9), Bang Chan (Stray Kids), MOON SUA of Billlie)","artist":"ASTRO","album":"Moon","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b273f61d48004e9cacd4fce6fd2d","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0IjaSeBp6SHXTELm4C9ifk","service":"spop","name":"FOREVER","artist":"D.O.","album":"Resident Playbook, Pt. 6 (Original Soundtrack)","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b273ff4618b6c70a8518fbd08625","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:3H1ikRF1DLYkI8CHr5J7cy in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:3H1ikRF1DLYkI8CHr5J7cy May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1z5ebC9238uGoBgzYyvGpQ","service":"spop","name":"toxic till the end","artist":"ROSÉ","album":"rosie","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b2735074bd0894cb1340b8d8a678","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:3gJAFFELdZyIM8tiwLAikg in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:3gJAFFELdZyIM8tiwLAikg May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3H1ikRF1DLYkI8CHr5J7cy","service":"spop","name":"Chains","artist":"HIGHLIGHT","album":"From Real to Surreal","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ef313fb054f6e62c0869b64","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:4Vpl8DJahXjdFHpEoZ8W11 in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:4Vpl8DJahXjdFHpEoZ8W11 May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3gJAFFELdZyIM8tiwLAikg","service":"spop","name":"Handlebars (feat. Dua Lipa)","artist":"JENNIE","album":"Ruby","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b2735a43918ea90bf1e44b7bdcfd","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:406IpEtZPvbxApWTGM3twY in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:406IpEtZPvbxApWTGM3twY May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4Vpl8DJahXjdFHpEoZ8W11","service":"spop","name":"Mrs. Nail","artist":"HyunA","album":"Mrs. Nail","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b2731922d4e36ef503e9ef6434ee","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:5r3nfTCyrc3KzNexD5pXyU in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:5r3nfTCyrc3KzNexD5pXyU May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:0GOqhXyouUxqPEw9ypTOLm in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:0GOqhXyouUxqPEw9ypTOLm May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:406IpEtZPvbxApWTGM3twY","service":"spop","name":"HOT","artist":"LE SSERAFIM","album":"HOT","type":"song","duration":143,"albumart":"https://i.scdn.co/image/ab67616d0000b27386efcf81bf1382daa2d2afe6","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:7C9YOYpERtlL1kRfiS4LMf in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:7C9YOYpERtlL1kRfiS4LMf May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5r3nfTCyrc3KzNexD5pXyU","service":"spop","name":"Breath","artist":"MINNIE","album":"Resident Playbook, Pt. 5 (Original Soundtrack)","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b273c44fdba5476cf108ef428c93","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0GOqhXyouUxqPEw9ypTOLm","service":"spop","name":"TOO BAD","artist":"G-DRAGON","album":"Übermensch","type":"song","duration":153,"albumart":"https://i.scdn.co/image/ab67616d0000b273e1b8e368ceafe1117e846859","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:1Ah8dQEPYpmtl7FRvXJOOU in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:1Ah8dQEPYpmtl7FRvXJOOU May 11 12:18:42 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7C9YOYpERtlL1kRfiS4LMf","service":"spop","name":"Broken Party","artist":"CHEN","album":"Broken Party","type":"song","duration":177,"albumart":"https://i.scdn.co/image/ab67616d0000b273e29091990f94d3acf7618ecd","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:42 volumio volumio[10103]: info: Exploding uri spotify:track:3YYJhvip3QCfKirhcLVJUf in service spop May 11 12:18:42 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:3YYJhvip3QCfKirhcLVJUf May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:1lcBt7LoEikqYmhUoa2cez in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:1lcBt7LoEikqYmhUoa2cez May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Ah8dQEPYpmtl7FRvXJOOU","service":"spop","name":"earthquake","artist":"JISOO","album":"AMORTAGE","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b27342d0387cc1851d5d82050b35","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3YYJhvip3QCfKirhcLVJUf","service":"spop","name":"Hell or Heaven","artist":"Kep1er","album":"Kep1er Japan 1st EP","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b273e72547b264a2c3cce4713c10","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:1j15Ar0qGDzIR0v3CQv3JL in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:1j15Ar0qGDzIR0v3CQv3JL May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1lcBt7LoEikqYmhUoa2cez","service":"spop","name":"number one girl","artist":"ROSÉ","album":"rosie","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b2735074bd0894cb1340b8d8a678","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:5yfhzEct1ulyU6g5oVRraj in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:5yfhzEct1ulyU6g5oVRraj May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1j15Ar0qGDzIR0v3CQv3JL","service":"spop","name":"Gnarly","artist":"KATSEYE","album":"Gnarly","type":"song","duration":137,"albumart":"https://i.scdn.co/image/ab67616d0000b2738a30c41e2c9336c293ebebfe","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:17WnCJhdwQxOIiBZBkYocN in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:17WnCJhdwQxOIiBZBkYocN May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5yfhzEct1ulyU6g5oVRraj","service":"spop","name":"KNOW ABOUT ME","artist":"NMIXX","album":"Fe3O4: FORWARD","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b273e7129d59bb7af19ad185b40e","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:4qzV2qURSJBVV9d7BkMx4g in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:4qzV2qURSJBVV9d7BkMx4g May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:17WnCJhdwQxOIiBZBkYocN","service":"spop","name":"O-RLY?","artist":"NEXZ","album":"O-RLY?","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb567f8c787faf92dd2e01c8","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:track:5Fhr3wqeieN5WDkAsqL1JJ in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:track:5Fhr3wqeieN5WDkAsqL1JJ May 11 12:18:43 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::volumioReplaceandPlayItems May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::ClearQueue May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::stop May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::stPlaybackTimer May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::updateTrackBlock May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrackBlock May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::serviceStop May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::serviceStop May 11 12:18:43 volumio volumio[10103]: info: ControllerMpd::stop May 11 12:18:43 volumio volumio[10103]: verbose: ControllerMpd::sendMpdCommand stop May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::clearPlayQueue May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::saveQueue May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::volumioPushQueue May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::addQueueItems May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::addQueueItems May 11 12:18:43 volumio volumio[10103]: info: Preload queue cleared May 11 12:18:43 volumio volumio[10103]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1DXdzMu6LHKCwj May 11 12:18:43 volumio volumio[10103]: info: Exploding uri spotify:user:spotify:playlist:37i9dQZF1DXdzMu6LHKCwj in service spop May 11 12:18:43 volumio volumio[10103]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:37i9dQZF1DXdzMu6LHKCwj May 11 12:18:43 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:18:43 volumio volumio[10103]: info: sendMpdCommand stop took 20 milliseconds May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4qzV2qURSJBVV9d7BkMx4g","service":"spop","name":"REBEL HEART","artist":"IVE","album":"IVE EMPATHY","type":"song","duration":188,"albumart":"https://i.scdn.co/image/ab67616d0000b273487f90022857e485ecc685eb","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Fhr3wqeieN5WDkAsqL1JJ","service":"spop","name":"MONA LISA","artist":"j-hope","album":"MONA LISA","type":"song","duration":137,"albumart":"https://i.scdn.co/image/ab67616d0000b273b62ed5bcd74bd9ab8b1f4406","samplerate":"160 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::volumioPushQueue May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::saveQueue May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::updateTrackBlock May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrackBlock May 11 12:18:43 volumio volumio[10103]: info: CoreCommandRouter::volumioPlay May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::play index 0 May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::stop May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::play index undefined May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:43 volumio volumio[10103]: info: CoreStateMachine::startPlaybackTimer May 11 12:18:43 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:43 volumio volumio[10103]: info: [1746937123840] ControllerSpotify::clearAddPlayTrack May 11 12:18:43 volumio volumio[10103]: info: Sending Spotify command with payload to local API: /player/play May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=debug msg="resolved context of track" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=trace msg="emitting websocket event: will_play" May 11 12:18:43 volumio volumio[10103]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","play_origin":"go-librespot"}} May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=debug msg="selected format OGG_VORBIS_160 (9bafb6d4504b36d9857110d62e3cbc0d3c03572a)" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:43 volumio go-librespot[10274]: time="2025-05-11T12:18:43+08:00" level=debug msg="requested aes key for file 9bafb6d4504b36d9857110d62e3cbc0d3c03572a, gid: 6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="fetched first chunk of 6, total size is 3015121 bytes" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="created new output device" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08: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" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=info msg="loaded track \"Pookie\" (paused: false, position: 0ms, duration: 152813ms, prefetched: false)" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=trace msg="scheduling prefetch in 123s" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=trace msg="emitting websocket event: metadata" May 11 12:18:44 volumio volumio[10103]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","name":"Pookie","artist_names":["FIFTY FIFTY"],"album_name":"Day \u0026 Night","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b878e64f5e7830e50a3f765d","position":0,"duration":152813,"release_date":"year:2025 month:4 day:29","track_number":1,"disc_number":1}} May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=trace msg="emitting websocket event: playing" May 11 12:18:44 volumio volumio[10103]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","play_origin":"go-librespot"}} May 11 12:18:44 volumio volumio[10103]: SPOTIFY: PUSH STATE SPOTIFY May 11 12:18:44 volumio volumio[10103]: SPOTIFY: {"status":"play","service":"spop","title":"Pookie","artist":"FIFTY FIFTY","album":"Day & Night","albumart":"https://i.scdn.co/image/ab67616d00001e02b878e64f5e7830e50a3f765d","uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 11 12:18:44 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:18:44 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:44 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Pookie","artist":"FIFTY FIFTY","album":"Day & Night","albumart":"https://i.scdn.co/image/ab67616d00001e02b878e64f5e7830e50a3f765d","uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 11 12:18:44 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus stop May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="fetched chunk 1/5, size: 524288" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="fetched chunk 3/5, size: 524288" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio go-librespot[10274]: time="2025-05-11T12:18:44+08:00" level=debug msg="fetched chunk 2/5, size: 524288" uri="spotify:track:6vw9OTw8rBhatDSdlxVIuF" May 11 12:18:44 volumio volumio[10103]: SPOTIFY: PUSH STATE SPOTIFY May 11 12:18:44 volumio volumio[10103]: SPOTIFY: {"status":"play","service":"spop","title":"Pookie","artist":"FIFTY FIFTY","album":"Day & Night","albumart":"https://i.scdn.co/image/ab67616d00001e02b878e64f5e7830e50a3f765d","uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 11 12:18:44 volumio volumio[10103]: info: CoreCommandRouter::servicePushState May 11 12:18:44 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:44 volumio volumio[10103]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Pookie","artist":"FIFTY FIFTY","album":"Day & Night","albumart":"https://i.scdn.co/image/ab67616d00001e02b878e64f5e7830e50a3f765d","uri":"spotify:track:6vw9OTw8rBhatDSdlxVIuF","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 11 12:18:44 volumio volumio[10103]: verbose: CURRENT POSITION 0 May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::syncState stateService play May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::syncState currentStatus play May 11 12:18:44 volumio volumio[10103]: info: Received an update from plugin. extracting info from payload May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:18:44 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:44 volumio volumio[10103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 12:18:44 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:18:44 volumio volumio[10103]: info: CoreStateMachine::pushState May 11 12:18:44 volumio volumio[10103]: info: CorePlayQueue::getTrack 0 May 11 12:18:44 volumio volumio[10103]: info: CoreCommandRouter::volumioPushState May 11 12:18:44 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:18:44 volumio volumio[10103]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 11 12:18:45 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:52 volumio wpa_supplicant[884]: RRM: Ignoring radio measurement request: Not RRM network May 11 12:18:53 volumio volumio[10103]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 12:18:53 volumio volumio[10103]: Error: connect ETIMEDOUT 151.101.130.79:443 May 11 12:18:53 volumio volumio[10103]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 11 12:18:53 volumio volumio[10103]: errno: -110, May 11 12:18:53 volumio volumio[10103]: code: 'ETIMEDOUT', May 11 12:18:53 volumio volumio[10103]: syscall: 'connect', May 11 12:18:53 volumio volumio[10103]: address: '151.101.130.79', May 11 12:18:53 volumio volumio[10103]: port: 443 May 11 12:18:53 volumio volumio[10103]: } May 11 12:18:53 volumio volumio[10103]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 12:18:53 volumio sudo[10797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-11 12:17 May 11 12:18:53 volumio sudo[10797]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"