May 28 08:15:33 volumio volumio[1286]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 28 08:15:33 volumio sudo[3951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 28 08:15:33 volumio sudo[3951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 08:15:33 volumio sudo[3951]: pam_unix(sudo:session): session closed for user root May 28 08:15:33 volumio sudo[3953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 28 08:15:33 volumio sudo[3953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 08:15:33 volumio volumio[1286]: info: MPD Permissions set May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 28 08:15:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 28 08:15:33 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 08:15:33 volumio systemd[1]: mpd.service: Deactivated successfully. May 28 08:15:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 28 08:15:33 volumio systemd[1]: mpd.service: Consumed 3.663s CPU time. May 28 08:15:33 volumio systemd[1]: mpd.socket: Deactivated successfully. May 28 08:15:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 28 08:15:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 28 08:15:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 28 08:15:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 28 08:15:33 volumio sudo[3965]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 28 08:15:33 volumio sudo[3965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 08:15:33 volumio sudo[3965]: pam_unix(sudo:session): session closed for user root May 28 08:15:33 volumio mpd[3967]: 2026-05-28T08:15:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 28 08:15:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 28 08:15:33 volumio sudo[3953]: pam_unix(sudo:session): session closed for user root May 28 08:15:33 volumio volumio[1286]: error: updateQueue error: null May 28 08:15:42 volumio volumio[1286]: info: Clearing queue after UPNP request May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::ClearQueue May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::stop May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::stPlaybackTimer May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::updateTrackBlock May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getTrackBlock May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::pushState May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::serviceStop May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 May 28 08:15:43 volumio volumio[1286]: info: ControllerMpd::stop May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand stop May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::clearPlayQueue May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::saveQueue May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioPushQueue May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: sendMpdCommand stop took 13 milliseconds May 28 08:15:43 volumio volumio[1286]: error: updateQueue error: null May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 1ms May 28 08:15:43 volumio volumio[1286]: info: Starting UPNP Playback May 28 08:15:43 volumio volumio[1286]: info: Preparing playback through UPNP May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioGetState May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getTrack 0 May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::setConsumeUpdateService mpd May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 0ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 1ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 0ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 1ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 0ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 1ms May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces state update: player May 28 08:15:43 volumio volumio[1286]: info: ControllerMpd::getState May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status May 28 08:15:43 volumio volumio[1286]: info: sendMpdCommand status took 44 milliseconds May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::parseState May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces state update: player May 28 08:15:43 volumio volumio[1286]: info: ControllerMpd::getState May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand status May 28 08:15:43 volumio volumio[1286]: info: May 28 08:15:43 volumio volumio[1286]: ---------------------------- MPD announces system playlist update May 28 08:15:43 volumio volumio[1286]: info: Ignoring MPD Status Update May 28 08:15:43 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 28 milliseconds May 28 08:15:43 volumio volumio[1286]: info: sendMpdCommand status took 28 milliseconds May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::parseState May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 08:15:43 volumio volumio[1286]: info: ControllerMpd::pushState May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::servicePushState May 28 08:15:43 volumio volumio[1286]: verbose: In UPNP mode May 28 08:15:43 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":263,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"一个真实的故事","artist":"朱哲琴","album":"歌声流淌四十年","uri":"http://sjy6.stream.qqmusic.qq.com/F000004YILee1RSrDU.flac?guid=ffffffffb34060500000019a1b3bc7c7&vkey=B8DC32E27A8A81C9C93FD4677E6699D41D3664841C2C39BFADAC57D1B6BAF4A008841A31A18A3BBAC2D0B42117D6F624BEC788C07070B44C__v2b9abfcf&uin=287143318&redirect=1&fromtag=111114","trackType":""} May 28 08:15:43 volumio volumio[1286]: verbose: CURRENT POSITION 0 May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus stop May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 76ms May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 1ms May 28 08:15:43 volumio volumio[1286]: info: sendMpdCommand playlistinfo took 1 milliseconds May 28 08:15:43 volumio volumio[1286]: verbose: ControllerMpd::parseTrackInfo May 28 08:15:43 volumio volumio[1286]: info: ControllerMpd::pushState May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::servicePushState May 28 08:15:43 volumio volumio[1286]: verbose: In UPNP mode May 28 08:15:43 volumio volumio[1286]: verbose: STATE SERVICE {"status":"play","position":0,"seek":479,"duration":263,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"一个真实的故事","artist":"朱哲琴","album":"歌声流淌四十年","uri":"http://sjy6.stream.qqmusic.qq.com/F000004YILee1RSrDU.flac?guid=ffffffffb34060500000019a1b3bc7c7&vkey=B8DC32E27A8A81C9C93FD4677E6699D41D3664841C2C39BFADAC57D1B6BAF4A008841A31A18A3BBAC2D0B42117D6F624BEC788C07070B44C__v2b9abfcf&uin=287143318&redirect=1&fromtag=111114","trackType":""} May 28 08:15:43 volumio volumio[1286]: verbose: CURRENT POSITION 0 May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::syncState stateService play May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::syncState currentStatus play May 28 08:15:43 volumio volumio[1286]: info: Received an update from plugin. extracting info from payload May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::pushState May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::pushState May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioPushState May 28 08:15:43 volumio volumio[1286]: info: ------------------------------ 36ms May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::getQueue May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getQueue May 28 08:15:43 volumio volumio[1286]: info: CoreCommandRouter::volumioGetQueue May 28 08:15:43 volumio volumio[1286]: info: CoreStateMachine::getQueue May 28 08:15:43 volumio volumio[1286]: info: CorePlayQueue::getQueue May 28 08:15:57 volumio volumio[1286]: verbose: New Socket.io Connection to 192.168.0.102 from 192.168.0.100 UA: Mozilla/5.0 (Linux; Android 16; ELP-AN00 Build/HONORELP-AN00;) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/97.0.4692.98 Mobile Safari/537.36 T7/13.38 SP-engine/2.76.0 languageType/0 bdh_dvt/0 bdh_de/0 bdh_ds/0 bdapp/1.0 (bdhonorbrowser; bdhonorbrowser) bdhonorbrowser/9.8.0.3 (P1 16) NABar/1.0 Engine version: 3 Transport: polling Total Clients: 6 May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::volumioGetVisibleSources May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::volumioGetState May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 28 08:15:57 volumio volumio[1286]: info: Received Get System Info May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 08:15:57 volumio volumio[1286]: info: Discovery: Getting this device information May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::volumioGetState May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 08:15:57 volumio volumio[1286]: info: CoreCommandRouter::volumioGetState May 28 08:15:57 volumio volumio[1286]: info: Listing playlists May 28 08:15:58 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::getUIConfigOnPlugin May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 28 08:16:09 volumio volumio[1286]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 28 08:16:16 volumio volumio[1286]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 08:16:16 volumio volumio[1286]: Error: connect ETIMEDOUT 31.13.86.21:443 May 28 08:16:16 volumio volumio[1286]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { May 28 08:16:16 volumio volumio[1286]: errno: -110, May 28 08:16:16 volumio volumio[1286]: code: 'ETIMEDOUT', May 28 08:16:16 volumio volumio[1286]: syscall: 'connect', May 28 08:16:16 volumio volumio[1286]: address: '31.13.86.21', May 28 08:16:16 volumio volumio[1286]: port: 443 May 28 08:16:16 volumio volumio[1286]: } May 28 08:16:16 volumio volumio[1286]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 08:16:16 volumio sudo[4223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-28 08:15' May 28 08:16:16 volumio sudo[4223]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"