-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Thu 2025-12-18 09:48:35 CST. -- Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 18 09:47:46 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 18 09:47:50 volumio volumio[950]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 18 09:47:50 volumio volumio[950]: info: Preparing to save Alsa Options, stopping services first Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioGetState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioPause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::pause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::stPlaybackTimer Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::servicePause Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::servicePause Dec 18 09:47:50 volumio volumio[950]: info: ControllerMpd::pause Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand pause Dec 18 09:47:50 volumio volumio[950]: info: Saving Audio Output to: {"output_device":{"value":"1,1","label":"SPDIF"}} Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 09:47:50 volumio volumio[950]: info: Found match in Cards Database: setting mixer for card SPDIF Dec 18 09:47:50 volumio volumio[950]: info: Setting mixer Headphone for card SPDIF Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 18 09:47:50 volumio volumio[950]: info: Updating Volume Controller Parameters: Device: 1,1 Name: SPDIF Mixer: Headphone Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 18 09:47:50 volumio volumio[950]: info: Disabling external Volume Control Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 18 09:47:50 volumio volumio[950]: info: Preparing to generate the ALSA configuration file Dec 18 09:47:50 volumio volumio[950]: info: Dec 18 09:47:50 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:47:50 volumio volumio[950]: info: sendMpdCommand pause took 135 milliseconds Dec 18 09:47:50 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:47:50 volumio volumio[950]: info: Dec 18 09:47:50 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:47:50 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:47:50 volumio volumio[950]: info: sendMpdCommand status took 2 milliseconds Dec 18 09:47:50 volumio volumio[950]: info: sendMpdCommand status took 1 milliseconds Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:47:50 volumio volumio[950]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 18 09:47:50 volumio volumio[950]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:47:50 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:47:50 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":61958,"duration":3851,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"?·??dz???","artist":"????","album":"???翪ʼ","uri":"USB/Ventoy/DSD音乐/彭羚-仿佛是初恋CD.wav","trackType":"wav"} Dec 18 09:47:50 volumio volumio[950]: verbose: CURRENT POSITION 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::syncState stateService pause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus pause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::stPlaybackTimer Dec 18 09:47:50 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":61958,"duration":3851,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"?·??dz???","artist":"????","album":"???翪ʼ","uri":"USB/Ventoy/DSD音乐/彭羚-仿佛是初恋CD.wav","trackType":"wav"} Dec 18 09:47:50 volumio volumio[950]: verbose: CURRENT POSITION 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::syncState stateService pause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus pause Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::stPlaybackTimer Dec 18 09:47:50 volumio volumio[950]: info: ------------------------------ 23ms Dec 18 09:47:50 volumio volumio[950]: info: ------------------------------ 22ms Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 18 09:47:50 volumio volumio[950]: info: Asound.conf file written Dec 18 09:47:50 volumio sudo[2608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 18 09:47:50 volumio sudo[2608]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio sudo[2608]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio volumio[950]: info: Output device has changed, restarting MPD Dec 18 09:47:50 volumio volumio[950]: info: Output device has changed, restarting Shairport Sync Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:50 volumio sudo[2620]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 18 09:47:50 volumio sudo[2620]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio sudo[2622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 18 09:47:50 volumio sudo[2620]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio sudo[2622]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio volumio[950]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 18 09:47:50 volumio volumio[950]: info: Output device has changed, restarting MPD Dec 18 09:47:50 volumio systemd[1]: Stopping Music Player Daemon... Dec 18 09:47:50 volumio volumio[950]: info: Output device has changed, restarting Shairport Sync Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:50 volumio sudo[2641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 18 09:47:50 volumio sudo[2643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 18 09:47:50 volumio sudo[2641]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio sudo[2641]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio sudo[2643]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio volumio[950]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 18 09:47:50 volumio volumio[950]: info: VolumeController:: Volume=100 Mute =false Dec 18 09:47:50 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:47:50 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:47:50 volumio systemd[1]: mpd.service: Succeeded. Dec 18 09:47:50 volumio systemd[1]: Stopped Music Player Daemon. Dec 18 09:47:50 volumio systemd[1]: Starting Music Player Daemon... Dec 18 09:47:50 volumio volumio[950]: info: MPD Permissions set Dec 18 09:47:50 volumio volumio[950]: info: MPD Permissions set Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 18 09:47:50 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 09:47:50 volumio volumio[950]: info: Starting Shairport Sync Dec 18 09:47:50 volumio sudo[2660]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 18 09:47:50 volumio volumio[950]: info: Starting Shairport Sync Dec 18 09:47:50 volumio sudo[2660]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio sudo[2677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 18 09:47:50 volumio sudo[2660]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio sudo[2677]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio sudo[2681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 18 09:47:50 volumio sudo[2681]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:50 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 18 09:47:50 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 18 09:47:50 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 18 09:47:50 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 18 09:47:50 volumio sudo[2677]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 18 09:47:50 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 18 09:47:50 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 18 09:47:50 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 18 09:47:50 volumio volumio[950]: info: Shairport-Sync Started Dec 18 09:47:50 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 18 09:47:50 volumio sudo[2681]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:50 volumio volumio[950]: info: Shairport-Sync Started Dec 18 09:47:51 volumio mpd[2700]: Dec 18 09:47 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 18 09:47:51 volumio systemd[1]: Started Music Player Daemon. Dec 18 09:47:51 volumio sudo[2643]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:51 volumio sudo[2622]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:51 volumio volumio[950]: error: MPD error: The expression evaluated to a falsy value: Dec 18 09:47:51 volumio volumio[950]: assert.ok(self.idling) Dec 18 09:47:51 volumio volumio[950]: error: The expression evaluated to a falsy value: Dec 18 09:47:51 volumio volumio[950]: assert.ok(self.idling) Dec 18 09:47:51 volumio volumio[950]: error: updateQueue error: null Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 18 09:47:54 volumio volumio[950]: info: CoreStateMachine::getcurrentVolume Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::volumioRetrievevolume Dec 18 09:47:54 volumio volumio[950]: info: VolumeController:: Volume=41 Mute =false Dec 18 09:47:54 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:47:54 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:47:54 volumio volumio[950]: info: CoreStateMachine::updateTrackBlock Dec 18 09:47:54 volumio volumio[950]: info: CorePlayQueue::getTrackBlock Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::volumioRetrievevolume Dec 18 09:47:54 volumio volumio[950]: info: VolumeController:: Volume=41 Mute =false Dec 18 09:47:54 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:47:54 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:47:54 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:47:54 volumio sudo[2719]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 18 09:47:54 volumio sudo[2721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 18 09:47:54 volumio sudo[2719]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:54 volumio sudo[2721]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 18 09:47:54 volumio systemd[1]: Stopping MPD Monitor Service... Dec 18 09:47:54 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 18 09:47:54 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 18 09:47:54 volumio systemd[1]: Stopped MPD Monitor Service. Dec 18 09:47:54 volumio systemd[1]: Started MPD Monitor Service. Dec 18 09:47:54 volumio mpd_monitor.sh[2732]: MPD Monitor Service: Starting MPD Monitor Service Dec 18 09:47:54 volumio sudo[2719]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:54 volumio systemd[1]: Stopping MPD Monitor Service... Dec 18 09:47:54 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 18 09:47:54 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 18 09:47:54 volumio systemd[1]: Stopped MPD Monitor Service. Dec 18 09:47:54 volumio systemd[1]: Started MPD Monitor Service. Dec 18 09:47:54 volumio sudo[2721]: pam_unix(sudo:session): session closed for user root Dec 18 09:47:54 volumio mpd_monitor.sh[2736]: MPD Monitor Service: Starting MPD Monitor Service Dec 18 09:47:54 volumio volumio[950]: info: Successfully started MPD Monitor Dec 18 09:47:54 volumio volumio[950]: info: Successfully started MPD Monitor Dec 18 09:48:00 volumio volumio[950]: info: VolumeController::SetAlsaVolume97 Dec 18 09:48:00 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:00 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:00 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:00 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:01 volumio volumio[950]: info: VolumeController::SetAlsaVolume98 Dec 18 09:48:01 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:01 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:01 volumio volumio[950]: info: VolumeController::SetAlsaVolume99 Dec 18 09:48:01 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:01 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:01 volumio volumio[950]: info: VolumeController::SetAlsaVolume100 Dec 18 09:48:01 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:01 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:01 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:02 volumio volumio[950]: info: VolumeController::SetAlsaVolume78 Dec 18 09:48:02 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:02 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:02 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:02 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:02 volumio volumio[950]: info: VolumeController::SetAlsaVolume70 Dec 18 09:48:02 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:02 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:02 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:02 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:08 volumio volumio[950]: info: CoreCommandRouter::volumioGetState Dec 18 09:48:08 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:09 volumio volumio[950]: info: CoreCommandRouter::volumioPlay Dec 18 09:48:09 volumio volumio[950]: info: CoreStateMachine::play index undefined Dec 18 09:48:09 volumio volumio[950]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 09:48:09 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:09 volumio volumio[950]: info: CoreStateMachine::startPlaybackTimer Dec 18 09:48:09 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:09 volumio volumio[950]: info: ControllerMpd::resume Dec 18 09:48:09 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand play Dec 18 09:48:09 volumio volumio[950]: info: sendMpdCommand play took 1 milliseconds Dec 18 09:48:12 volumio volumio[950]: info: CoreCommandRouter::volumioPlay Dec 18 09:48:12 volumio volumio[950]: info: CoreStateMachine::play index undefined Dec 18 09:48:12 volumio volumio[950]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 09:48:12 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:12 volumio volumio[950]: info: CoreStateMachine::startPlaybackTimer Dec 18 09:48:12 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:12 volumio volumio[950]: info: ControllerMpd::resume Dec 18 09:48:12 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand play Dec 18 09:48:12 volumio volumio[950]: info: sendMpdCommand play took 0 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::volumioNext Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::next Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::stop Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::updateTrackBlock Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrackBlock Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::stPlaybackTimer Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::serviceStop Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 0 Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::serviceStop Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::stop Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand stop Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand stop took 5 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::play index undefined Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::startPlaybackTimer Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::clearAddPlayTracks USB/Ventoy/DSD音乐/辛曉琪-味道.dsf Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand stop Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::updateTrackBlock Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrackBlock Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand stop took 1 milliseconds Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand clear Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces system playlist update Dec 18 09:48:14 volumio volumio[950]: info: Ignoring MPD Status Update Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand clear took 1 milliseconds Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand add "USB/Ventoy/DSD音乐/辛曉琪-味道.dsf" Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces system playlist update Dec 18 09:48:14 volumio volumio[950]: info: Ignoring MPD Status Update Dec 18 09:48:14 volumio volumio[950]: error: updateQueue error: null Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces system playlist update Dec 18 09:48:14 volumio volumio[950]: info: Ignoring MPD Status Update Dec 18 09:48:14 volumio volumio[950]: info: ------------------------------ 3ms Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand add "USB/Ventoy/DSD音乐/辛曉琪-味道.dsf" took 2 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: ------------------------------ 2ms Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand play Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces system playlist update Dec 18 09:48:14 volumio volumio[950]: info: Ignoring MPD Status Update Dec 18 09:48:14 volumio volumio[950]: info: ------------------------------ 3ms Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand play took 2 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: ------------------------------ 1ms Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand status took 16 milliseconds Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand status took 19 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"味道","artist":"辛曉琪","album":"滾石 24K24Bit 珍藏版金碟系列","uri":"USB/Ventoy/DSD音乐/辛曉琪-味道.dsf","trackType":"dsf"} Dec 18 09:48:14 volumio volumio[950]: verbose: CURRENT POSITION 1 Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::syncState stateService play Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus stop Dec 18 09:48:14 volumio volumio[950]: info: ------------------------------ 24ms Dec 18 09:48:14 volumio volumio[950]: info: Dec 18 09:48:14 volumio volumio[950]: ---------------------------- MPD announces state update: player Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::getState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand status Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand status took 7 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 18 09:48:14 volumio volumio[950]: info: sendMpdCommand status took 2 milliseconds Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::parseState Dec 18 09:48:14 volumio volumio[950]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 09:48:14 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"味道","artist":"辛曉琪","album":"滾石 24K24Bit 珍藏版金碟系列","uri":"USB/Ventoy/DSD音乐/辛曉琪-味道.dsf","trackType":"dsf"} Dec 18 09:48:14 volumio volumio[950]: verbose: CURRENT POSITION 1 Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::syncState stateService play Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus play Dec 18 09:48:14 volumio volumio[950]: info: Received an update from plugin. extracting info from payload Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:14 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:14 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:14 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:15 volumio volumio[950]: info: ------------------------------ 46ms Dec 18 09:48:15 volumio volumio[950]: info: sendMpdCommand playlistinfo took 21 milliseconds Dec 18 09:48:15 volumio volumio[950]: info: sendMpdCommand playlistinfo took 22 milliseconds Dec 18 09:48:15 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:48:15 volumio volumio[950]: verbose: ControllerMpd::parseTrackInfo Dec 18 09:48:15 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: verbose: STATE SERVICE {"status":"play","position":0,"seek":125,"duration":241,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"味道","artist":"辛曉琪","album":"滾石 24K24Bit 珍藏版金碟系列","uri":"USB/Ventoy/DSD音乐/辛曉琪-味道.dsf","trackType":"dsf"} Dec 18 09:48:15 volumio volumio[950]: verbose: CURRENT POSITION 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::syncState stateService play Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus play Dec 18 09:48:15 volumio volumio[950]: info: Received an update from plugin. extracting info from payload Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:15 volumio volumio[950]: info: ControllerMpd::pushState Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::servicePushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: verbose: STATE SERVICE {"status":"play","position":0,"seek":285,"duration":241,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"味道","artist":"辛曉琪","album":"滾石 24K24Bit 珍藏版金碟系列","uri":"USB/Ventoy/DSD音乐/辛曉琪-味道.dsf","trackType":"dsf"} Dec 18 09:48:15 volumio volumio[950]: verbose: CURRENT POSITION 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::syncState stateService play Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::syncState currentStatus play Dec 18 09:48:15 volumio volumio[950]: info: Received an update from plugin. extracting info from payload Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:15 volumio volumio[950]: info: CoreStateMachine::pushState Dec 18 09:48:15 volumio volumio[950]: info: CorePlayQueue::getTrack 1 Dec 18 09:48:15 volumio volumio[950]: info: CoreCommandRouter::volumioPushState Dec 18 09:48:15 volumio volumio[950]: info: ------------------------------ 65ms Dec 18 09:48:15 volumio volumio[950]: info: ------------------------------ 60ms Dec 18 09:48:34 volumio volumio[950]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 09:48:34 volumio volumio[950]: Error: connect ETIMEDOUT 31.13.96.192:443 Dec 18 09:48:34 volumio volumio[950]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Dec 18 09:48:34 volumio volumio[950]: errno: -110, Dec 18 09:48:34 volumio volumio[950]: code: 'ETIMEDOUT', Dec 18 09:48:34 volumio volumio[950]: syscall: 'connect', Dec 18 09:48:34 volumio volumio[950]: address: '31.13.96.192', Dec 18 09:48:34 volumio volumio[950]: port: 443 Dec 18 09:48:34 volumio volumio[950]: } Dec 18 09:48:34 volumio volumio[950]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 09:48:35 volumio sudo[2832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-18 09:47 Dec 18 09:48:35 volumio sudo[2832]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 07:17:52 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="3b20d491450ccf59e0e519a97572dc60"