Feb 24 21:39:02 volumio-z8350 volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:39:02 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 24 21:39:02 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:39:02 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 24 21:39:03 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetState Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: Restoring Previous Volume level: 40 false false Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: Volume configurations have been set Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: Updating Volume Controller Parameters: Device: 5 Name: DA5 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: Disabling external Volume Control Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: VolumeController:: Volume=40 Mute =false Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:20 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: VolumeController::SetAlsaVolume40 Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:24 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:26 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::stPlaybackTimer Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::servicePause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: [1771940368562] ControllerUPNPBrowser::pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: Feb 24 21:39:28 volumio-z8350 volumio[1379]: ---------------------------- MPD announces state update: player Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: sendMpdCommand pause took 6 milliseconds Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ControllerMpd::getState Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand status Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: Feb 24 21:39:28 volumio-z8350 volumio[1379]: ---------------------------- MPD announces state update: player Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ControllerMpd::getState Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand status Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: sendMpdCommand status took 6 milliseconds Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseState Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: sendMpdCommand status took 6 milliseconds Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseState Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseTrackInfo Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ControllerMpd::pushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":55980,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"745 Kbps","isStreaming":false,"title":"Besame Mucho","artist":"Andrea Bocelli","album":"15首全球至伤情歌壹","uri":"http://192.168.1.123:9790/minimserver/*/music01/*5bSelection*5d/Besame_Mucho-Andrea_Bocelli-591952.flac","trackType":"flac"} Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: CURRENT POSITION 0 Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState stateService pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState currentStatus pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::stPlaybackTimer Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ------------------------------ 57ms Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: sendMpdCommand playlistinfo took 33 milliseconds Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseTrackInfo Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ControllerMpd::pushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":55980,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"745 Kbps","isStreaming":false,"title":"Besame Mucho","artist":"Andrea Bocelli","album":"15首全球至伤情歌壹","uri":"http://192.168.1.123:9790/minimserver/*/music01/*5bSelection*5d/Besame_Mucho-Andrea_Bocelli-591952.flac","trackType":"flac"} Feb 24 21:39:28 volumio-z8350 volumio[1379]: verbose: CURRENT POSITION 0 Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState stateService pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState currentStatus pause Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::stPlaybackTimer Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: ------------------------------ 80ms Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:28 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPlay Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::play index undefined Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::startPlaybackTimer Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: [1771940370650] ControllerUPNPBrowser::resume Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand play Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: Feb 24 21:39:30 volumio-z8350 volumio[1379]: ---------------------------- MPD announces state update: player Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: sendMpdCommand play took 9 milliseconds Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ControllerMpd::getState Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand status Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: Feb 24 21:39:30 volumio-z8350 volumio[1379]: ---------------------------- MPD announces state update: player Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ControllerMpd::getState Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand status Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: sendMpdCommand status took 6 milliseconds Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: sendMpdCommand status took 3 milliseconds Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseState Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseState Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseTrackInfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: ControllerMpd::parseTrackInfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ControllerMpd::pushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: STATE SERVICE {"status":"play","position":0,"seek":56846,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"723 Kbps","isStreaming":false,"title":"Besame Mucho","artist":"Andrea Bocelli","album":"15首全球至伤情歌壹","uri":"http://192.168.1.123:9790/minimserver/*/music01/*5bSelection*5d/Besame_Mucho-Andrea_Bocelli-591952.flac","trackType":"flac"} Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: CURRENT POSITION 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState stateService play Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState currentStatus pause Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ControllerMpd::pushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: STATE SERVICE {"status":"play","position":0,"seek":56846,"duration":244,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"723 Kbps","isStreaming":false,"title":"Besame Mucho","artist":"Andrea Bocelli","album":"15首全球至伤情歌壹","uri":"http://192.168.1.123:9790/minimserver/*/music01/*5bSelection*5d/Besame_Mucho-Andrea_Bocelli-591952.flac","trackType":"flac"} Feb 24 21:39:30 volumio-z8350 volumio[1379]: verbose: CURRENT POSITION 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState stateService play Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::syncState currentStatus play Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: Received an update from plugin. extracting info from payload Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ------------------------------ 79ms Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: ------------------------------ 76ms Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:39:30 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 24 21:39:49 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:17 volumio-z8350 sudo[3285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 21:40:17 volumio-z8350 sudo[3283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 21:40:17 volumio-z8350 sudo[3285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 21:40:17 volumio-z8350 sudo[3283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 21:40:17 volumio-z8350 sudo[3283]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:17 volumio-z8350 volumio[1379]: info: MPD Permissions set Feb 24 21:40:17 volumio-z8350 systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 24 21:40:17 volumio-z8350 systemd[1]: mpd.service: Deactivated successfully. Feb 24 21:40:17 volumio-z8350 systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 24 21:40:17 volumio-z8350 systemd[1]: mpd.service: Consumed 2.785s CPU time. Feb 24 21:40:17 volumio-z8350 systemd[1]: mpd.socket: Deactivated successfully. Feb 24 21:40:17 volumio-z8350 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 24 21:40:17 volumio-z8350 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 24 21:40:17 volumio-z8350 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 24 21:40:17 volumio-z8350 systemd[1]: Starting mpd.service - Music Player Daemon... Feb 24 21:40:17 volumio-z8350 sudo[3297]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 21:40:17 volumio-z8350 sudo[3297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 24 21:40:17 volumio-z8350 sudo[3297]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:19 volumio-z8350 mpd[3299]: 2026-02-24T21:40:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 21:40:19 volumio-z8350 systemd[1]: Started mpd.service - Music Player Daemon. Feb 24 21:40:19 volumio-z8350 sudo[3285]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:19 volumio-z8350 volumio[1379]: error: updateQueue error: null Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetState Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Restoring Previous Volume level: 100 false false Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Output device has changed, restarting MPD Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Output device has changed, restarting Shairport Sync Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:40:25 volumio-z8350 sudo[3325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 21:40:25 volumio-z8350 sudo[3325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 21:40:25 volumio-z8350 sudo[3325]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:25 volumio-z8350 sudo[3327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 21:40:25 volumio-z8350 sudo[3327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Volume configurations have been set Feb 24 21:40:25 volumio-z8350 systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Updating Volume Controller Parameters: Device: 5 Name: DA5 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 24 21:40:25 volumio-z8350 systemd[1]: mpd.service: Deactivated successfully. Feb 24 21:40:25 volumio-z8350 systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 24 21:40:25 volumio-z8350 systemd[1]: mpd.service: Consumed 1.620s CPU time. Feb 24 21:40:25 volumio-z8350 systemd[1]: mpd.socket: Deactivated successfully. Feb 24 21:40:25 volumio-z8350 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 24 21:40:25 volumio-z8350 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Disabling external Volume Control Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:40:25 volumio-z8350 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 24 21:40:25 volumio-z8350 systemd[1]: Starting mpd.service - Music Player Daemon... Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: MPD Permissions set Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 sudo[3340]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 21:40:25 volumio-z8350 sudo[3340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 24 21:40:25 volumio-z8350 sudo[3340]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Starting Shairport Sync Feb 24 21:40:25 volumio-z8350 sudo[3358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 21:40:25 volumio-z8350 sudo[3358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 21:40:25 volumio-z8350 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 24 21:40:25 volumio-z8350 systemd[1]: shairport-sync.service: Deactivated successfully. Feb 24 21:40:25 volumio-z8350 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 24 21:40:25 volumio-z8350 systemd[1]: shairport-sync.service: Consumed 4.195s CPU time. Feb 24 21:40:25 volumio-z8350 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 24 21:40:25 volumio-z8350 sudo[3358]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:25 volumio-z8350 volumio[1379]: info: Shairport-Sync Started Feb 24 21:40:26 volumio-z8350 mpd[3356]: 2026-02-24T21:40:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 21:40:26 volumio-z8350 systemd[1]: Started mpd.service - Music Player Daemon. Feb 24 21:40:26 volumio-z8350 sudo[3327]: pam_unix(sudo:session): session closed for user root Feb 24 21:40:27 volumio-z8350 volumio[1379]: error: updateQueue error: null Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: VolumeController::SetAlsaVolume100 Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CoreStateMachine::pushState Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPushState Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetQueue Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CoreStateMachine::getQueue Feb 24 21:40:29 volumio-z8350 volumio[1379]: info: CorePlayQueue::getQueue Feb 24 21:40:32 volumio-z8350 ntpd[1130]: CLOCK: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 24 21:40:34 volumio-z8350 volumio[1379]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%A7%9A%E6%96%AF%E5%A9%B7/LOVE%20II/2eb3ad80-84cd-4569-b185-b7d801929d13.jpg' Feb 24 21:40:34 volumio-z8350 volumio[1379]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/USA%20for%20Africa/We%20Are%20The%20World/8dba2886-81be-46b9-afc8-ac9815e1283d.png' Feb 24 21:40:34 volumio-z8350 volumio[1379]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E6%9D%8E%E5%AE%97%E7%9B%9B/2013%E6%9C%80%E6%96%B0%E5%96%AE%E6%9B%B2%E3%80%8C%E5%B1%B1%E4%B8%98%20%E3%80%8D/55af9d0a-9546-4342-b21b-007bf43f2603.jpg' Feb 24 21:40:34 volumio-z8350 volumio[1379]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Kari%20Bremnes/Norwegian%20Mood/5d16ed4a-73e3-44f9-b771-8b3518455e83.png' Feb 24 21:40:37 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioGetState Feb 24 21:40:37 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CoreStateMachine::stPlaybackTimer Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CoreStateMachine::servicePause Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CorePlayQueue::getTrack 0 Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: CoreCommandRouter::servicePause Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: [1771940438876] ControllerUPNPBrowser::pause Feb 24 21:40:38 volumio-z8350 volumio[1379]: verbose: ControllerMpd::sendMpdCommand pause Feb 24 21:40:38 volumio-z8350 volumio[1379]: info: sendMpdCommand pause took 2 milliseconds Feb 24 21:40:40 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:40 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:41 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:41 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:41 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:41 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:42 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:42 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:44 volumio-z8350 volumio[1379]: info: CoreCommandRouter::volumioPause Feb 24 21:40:44 volumio-z8350 volumio[1379]: info: CoreStateMachine::pause Feb 24 21:40:45 volumio-z8350 volumio[1379]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:40:45 volumio-z8350 volumio[1379]: Error: connect ETIMEDOUT 108.160.169.174:443 Feb 24 21:40:45 volumio-z8350 volumio[1379]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 24 21:40:45 volumio-z8350 volumio[1379]: errno: -110, Feb 24 21:40:45 volumio-z8350 volumio[1379]: code: 'ETIMEDOUT', Feb 24 21:40:45 volumio-z8350 volumio[1379]: syscall: 'connect', Feb 24 21:40:45 volumio-z8350 volumio[1379]: address: '108.160.169.174', Feb 24 21:40:45 volumio-z8350 volumio[1379]: port: 443 Feb 24 21:40:45 volumio-z8350 volumio[1379]: } Feb 24 21:40:45 volumio-z8350 volumio[1379]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 21:40:45 volumio-z8350 sudo[3467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-24 21:39' Feb 24 21:40:45 volumio-z8350 sudo[3467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"