-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Sun 2025-10-26 16:13:39 CST. -- Oct 26 16:12:00 volumio volumio[2391]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioGetState Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: Restoring Previous Volume level: 100 false true Oct 26 16:12:00 volumio volumio[2391]: info: VolumeController::SetAlsaVolume100 Oct 26 16:12:00 volumio volumio[2391]: info: Enable softmixer device for audio device number 0 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioStop Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::stop Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::stPlaybackTimer Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::updateTrackBlock Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrackBlock Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::serviceStop Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::serviceStop Oct 26 16:12:00 volumio volumio[2391]: info: ControllerMpd::stop Oct 26 16:12:00 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand stop Oct 26 16:12:00 volumio volumio[2391]: info: Enable softmixer device for audio device undefined Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 26 16:12:00 volumio volumio[2391]: info: Updating Volume Controller Parameters: Device: 0 Name: Volumio Zero ES9039 DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 26 16:12:00 volumio volumio[2391]: info: Disabling external Volume Control Oct 26 16:12:00 volumio volumio[2391]: info: Output device has changed, restarting MPD Oct 26 16:12:00 volumio sudo[2968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 16:12:00 volumio sudo[2968]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:00 volumio volumio[2391]: info: Output device has changed, restarting Shairport Sync Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:00 volumio sudo[2968]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:00 volumio sudo[2971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 16:12:00 volumio sudo[2971]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:00 volumio systemd[1]: Stopping Music Player Daemon... Oct 26 16:12:00 volumio volumio[2391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 16:12:00 volumio volumio[2391]: info: Volume configurations have been set Oct 26 16:12:00 volumio systemd[1]: mpd.service: Succeeded. Oct 26 16:12:00 volumio systemd[1]: Stopped Music Player Daemon. Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 26 16:12:00 volumio volumio[2391]: info: Updating Volume Controller Parameters: Device: 0 Name: Volumio Zero ES9039 DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 26 16:12:00 volumio volumio[2391]: info: Disabling external Volume Control Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:00 volumio volumio[2391]: error: MPD error: Error: write EPIPE Oct 26 16:12:00 volumio volumio[2391]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Oct 26 16:12:00 volumio systemd[1]: Starting Music Player Daemon... Oct 26 16:12:00 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:00 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:00 volumio volumio[2391]: info: MPD Permissions set Oct 26 16:12:00 volumio volumio[2391]: info: Software Volume ALSA configuration written Oct 26 16:12:00 volumio volumio[2391]: info: Preparing to generate the ALSA configuration file Oct 26 16:12:00 volumio volumio[2391]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 26 16:12:00 volumio volumio[2391]: info: Reading ALSA contributions from plugins. Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:00 volumio sudo[2978]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 16:12:00 volumio sudo[2978]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:00 volumio sudo[2978]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 26 16:12:00 volumio volumio[2391]: info: Getting Alsa Cards List without I2S DAC Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 26 16:12:00 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 26 16:12:00 volumio volumio[2391]: info: Starting Shairport Sync Oct 26 16:12:00 volumio sudo[3000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 16:12:00 volumio sudo[3000]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:00 volumio volumio[2391]: info: Asound.conf file written Oct 26 16:12:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 26 16:12:01 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 26 16:12:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:01 volumio sudo[3003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 26 16:12:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:01 volumio volumio[2391]: info: Output device has changed, restarting MPD Oct 26 16:12:01 volumio sudo[3003]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:01 volumio sudo[3003]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:01 volumio sudo[3000]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:01 volumio sudo[3009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 16:12:01 volumio sudo[3009]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:01 volumio volumio[2391]: info: Output device has changed, restarting Shairport Sync Oct 26 16:12:01 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:01 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:01 volumio sudo[3009]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:01 volumio sudo[3013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 16:12:01 volumio sudo[3013]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:01 volumio volumio[2391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 16:12:01 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 26 16:12:01 volumio systemd[1]: mpd.service: Succeeded. Oct 26 16:12:01 volumio systemd[1]: Stopped Music Player Daemon. Oct 26 16:12:01 volumio systemd[1]: Starting Music Player Daemon... Oct 26 16:12:01 volumio sudo[3020]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 16:12:01 volumio sudo[3020]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:01 volumio sudo[3020]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:01 volumio mpd[3023]: Oct 26 16:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 26 16:12:01 volumio systemd[1]: Started Music Player Daemon. Oct 26 16:12:01 volumio sudo[3013]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:01 volumio sudo[2971]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio volumio[2391]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Oct 26 16:12:02 volumio volumio[2391]: info: Output device has changed, restarting MPD Oct 26 16:12:02 volumio sudo[3029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 26 16:12:02 volumio sudo[3029]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:02 volumio volumio[2391]: info: Output device has changed, restarting Shairport Sync Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:02 volumio sudo[3029]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio sudo[3032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 16:12:02 volumio sudo[3032]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:02 volumio systemd[1]: Stopping Music Player Daemon... Oct 26 16:12:02 volumio volumio[2391]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 26 16:12:02 volumio systemd[1]: mpd.service: Succeeded. Oct 26 16:12:02 volumio systemd[1]: Stopped Music Player Daemon. Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 26 16:12:02 volumio volumio[2391]: info: Updating Volume Controller Parameters: Device: 0 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 26 16:12:02 volumio volumio[2391]: info: Disabling external Volume Control Oct 26 16:12:02 volumio volumio[2391]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 26 16:12:02 volumio volumio[2391]: info: MPD Permissions set Oct 26 16:12:02 volumio systemd[1]: Starting Music Player Daemon... Oct 26 16:12:02 volumio volumio[2391]: info: MPD Permissions set Oct 26 16:12:02 volumio volumio[2391]: info: Shairport-Sync Started Oct 26 16:12:02 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:02 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio sudo[3039]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 16:12:02 volumio sudo[3039]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:02 volumio sudo[3039]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:02 volumio volumio[2391]: info: Starting Shairport Sync Oct 26 16:12:02 volumio volumio[2391]: info: Starting Shairport Sync Oct 26 16:12:02 volumio sudo[3058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 16:12:02 volumio sudo[3058]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:02 volumio sudo[3061]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 26 16:12:02 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 26 16:12:02 volumio sudo[3061]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:02 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 26 16:12:02 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:02 volumio sudo[3058]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 26 16:12:02 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 26 16:12:02 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 26 16:12:02 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:02 volumio volumio[2391]: info: Shairport-Sync Started Oct 26 16:12:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 26 16:12:02 volumio sudo[3061]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio volumio[2391]: info: Shairport-Sync Started Oct 26 16:12:02 volumio mpd[3056]: Oct 26 16:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 26 16:12:02 volumio systemd[1]: Started Music Player Daemon. Oct 26 16:12:02 volumio sudo[3032]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:02 volumio volumio[2391]: error: MPD error: The expression evaluated to a falsy value: Oct 26 16:12:02 volumio volumio[2391]: assert.ok(self.idling) Oct 26 16:12:02 volumio volumio[2391]: error: The expression evaluated to a falsy value: Oct 26 16:12:02 volumio volumio[2391]: assert.ok(self.idling) Oct 26 16:12:02 volumio volumio[2391]: error: updateQueue error: null Oct 26 16:12:02 volumio volumio[2391]: error: updateQueue error: null Oct 26 16:12:03 volumio volumio[2391]: info: VolumeController::SetAlsaVolume45 Oct 26 16:12:03 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:03 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:03 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:03 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:03 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Oct 26 16:12:03 volumio sudo[3071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 26 16:12:03 volumio sudo[3071]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:03 volumio systemd[1]: Stopping Music Player Daemon... Oct 26 16:12:03 volumio systemd[1]: mpd.service: Succeeded. Oct 26 16:12:03 volumio systemd[1]: Stopped Music Player Daemon. Oct 26 16:12:03 volumio systemd[1]: Starting Music Player Daemon... Oct 26 16:12:04 volumio sudo[3073]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 26 16:12:04 volumio sudo[3073]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 26 16:12:04 volumio sudo[3073]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:04 volumio mpd[3076]: Oct 26 16:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 26 16:12:04 volumio systemd[1]: Started Music Player Daemon. Oct 26 16:12:04 volumio sudo[3071]: pam_unix(sudo:session): session closed for user root Oct 26 16:12:04 volumio volumio[2391]: error: updateQueue error: null Oct 26 16:12:05 volumio volumio[2391]: info: VolumeController::SetAlsaVolume30 Oct 26 16:12:05 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:05 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:05 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:05 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:05 volumio volumio[2391]: info: VolumeController::SetAlsaVolume100 Oct 26 16:12:05 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:05 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:05 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:05 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:05 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::volumioPlay Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::play index undefined Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::startPlaybackTimer Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::clearAddPlayTracks NAS/Volumio/日语/Eurobeat/Akiba Koubou/!Others/ayu-mi-x 7 presents ayu-ro mix 4/07. Boys & Girls (SUNNY DAY SCP version).flac Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand stop Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand stop took 0 milliseconds Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand clear Oct 26 16:12:09 volumio volumio[2391]: info: Oct 26 16:12:09 volumio volumio[2391]: ---------------------------- MPD announces system playlist update Oct 26 16:12:09 volumio volumio[2391]: info: Ignoring MPD Status Update Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand clear took 1 milliseconds Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand add "NAS/Volumio/日语/Eurobeat/Akiba Koubou/!Others/ayu-mi-x 7 presents ayu-ro mix 4/07. Boys & Girls (SUNNY DAY SCP version).flac" Oct 26 16:12:09 volumio volumio[2391]: error: updateQueue error: null Oct 26 16:12:09 volumio volumio[2391]: info: Oct 26 16:12:09 volumio volumio[2391]: ---------------------------- MPD announces system playlist update Oct 26 16:12:09 volumio volumio[2391]: info: Ignoring MPD Status Update Oct 26 16:12:09 volumio volumio[2391]: info: ------------------------------ 1ms Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand add "NAS/Volumio/日语/Eurobeat/Akiba Koubou/!Others/ayu-mi-x 7 presents ayu-ro mix 4/07. Boys & Girls (SUNNY DAY SCP version).flac" took 0 milliseconds Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand play Oct 26 16:12:09 volumio volumio[2391]: info: ------------------------------ 1ms Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand play took 1 milliseconds Oct 26 16:12:09 volumio volumio[2391]: info: Oct 26 16:12:09 volumio volumio[2391]: ---------------------------- MPD announces state update: player Oct 26 16:12:09 volumio volumio[2391]: info: ControllerMpd::getState Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:12:09 volumio volumio[2391]: info: Oct 26 16:12:09 volumio volumio[2391]: ---------------------------- MPD announces state update: player Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand status took 9 milliseconds Oct 26 16:12:09 volumio volumio[2391]: info: ControllerMpd::getState Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand status Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::parseState Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand status took 1 milliseconds Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::parseState Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:12:09 volumio volumio[2391]: info: ControllerMpd::pushState Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::servicePushState Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Boys & Girls (SUNNY DAY SCP version)","artist":"浜崎あゆみ","album":"ayu-mi-x 7 presents ayu-ro mix 4","uri":"NAS/Volumio/日语/Eurobeat/Akiba Koubou/!Others/ayu-mi-x 7 presents ayu-ro mix 4/07. Boys & Girls (SUNNY DAY SCP version).flac","trackType":"flac"} Oct 26 16:12:09 volumio volumio[2391]: verbose: CURRENT POSITION 174 Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::syncState stateService play Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::syncState currentStatus stop Oct 26 16:12:09 volumio volumio[2391]: info: ------------------------------ 12ms Oct 26 16:12:09 volumio volumio[2391]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 26 16:12:09 volumio volumio[2391]: verbose: ControllerMpd::parseTrackInfo Oct 26 16:12:09 volumio volumio[2391]: info: ControllerMpd::pushState Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::servicePushState Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Boys & Girls (SUNNY DAY SCP version)","artist":"浜崎あゆみ","album":"ayu-mi-x 7 presents ayu-ro mix 4","uri":"NAS/Volumio/日语/Eurobeat/Akiba Koubou/!Others/ayu-mi-x 7 presents ayu-ro mix 4/07. Boys & Girls (SUNNY DAY SCP version).flac","trackType":"flac"} Oct 26 16:12:09 volumio volumio[2391]: verbose: CURRENT POSITION 174 Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::syncState stateService play Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::syncState currentStatus play Oct 26 16:12:09 volumio volumio[2391]: info: Received an update from plugin. extracting info from payload Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:09 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:09 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:09 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:09 volumio volumio[2391]: info: ------------------------------ 11ms Oct 26 16:12:11 volumio volumio[2391]: info: VolumeController::SetAlsaVolume50 Oct 26 16:12:11 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:11 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:11 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:11 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:14 volumio volumio[2391]: info: VolumeController::SetAlsaVolume65 Oct 26 16:12:14 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:14 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:14 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:14 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:14 volumio volumio[2391]: info: VolumeController::SetAlsaVolume90 Oct 26 16:12:14 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:14 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:14 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:14 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:12:29 volumio volumio[2391]: info: VolumeController::SetAlsaVolume100 Oct 26 16:12:29 volumio volumio[2391]: info: CoreStateMachine::pushState Oct 26 16:12:29 volumio volumio[2391]: info: CorePlayQueue::getTrack 174 Oct 26 16:12:29 volumio volumio[2391]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 16:12:29 volumio volumio[2391]: info: CoreCommandRouter::volumioPushState Oct 26 16:13:39 volumio volumio[2391]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 16:13:39 volumio volumio[2391]: Error: connect ETIMEDOUT 75.126.164.178:443 Oct 26 16:13:39 volumio volumio[2391]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Oct 26 16:13:39 volumio volumio[2391]: errno: -110, Oct 26 16:13:39 volumio volumio[2391]: code: 'ETIMEDOUT', Oct 26 16:13:39 volumio volumio[2391]: syscall: 'connect', Oct 26 16:13:39 volumio volumio[2391]: address: '75.126.164.178', Oct 26 16:13:39 volumio volumio[2391]: port: 443 Oct 26 16:13:39 volumio volumio[2391]: } Oct 26 16:13:39 volumio volumio[2391]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 16:13:39 volumio sudo[3296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-26 16:12 Oct 26 16:13:39 volumio sudo[3296]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"