May 31 12:25:02 volumio volumio[1305]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioGetState May 31 12:25:02 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:02 volumio volumio[1305]: info: Restoring Previous Volume level: 0 false true May 31 12:25:02 volumio volumio[1305]: info: VolumeController::SetAlsaVolume100 May 31 12:25:02 volumio volumio[1305]: info: Enable softmixer device for audio device number 2 May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioStop May 31 12:25:02 volumio volumio[1305]: info: CoreStateMachine::stop May 31 12:25:02 volumio volumio[1305]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 12:25:02 volumio volumio[1305]: info: Enable softmixer device for audio device undefined May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 12:25:02 volumio volumio[1305]: info: Updating Volume Controller Parameters: Device: 2 Name: Soekris dam 1021 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 12:25:02 volumio volumio[1305]: info: Disabling external Volume Control May 31 12:25:02 volumio volumio[1305]: info: Output device has changed, restarting MPD May 31 12:25:02 volumio volumio[1305]: info: Output device has changed, restarting Shairport Sync May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:02 volumio sudo[1846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 12:25:02 volumio sudo[1846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:02 volumio sudo[1846]: pam_unix(sudo:session): session closed for user root May 31 12:25:02 volumio volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 12:25:02 volumio volumio[1305]: info: Volume configurations have been set May 31 12:25:02 volumio sudo[1849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 12:25:02 volumio sudo[1849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 12:25:02 volumio volumio[1305]: info: Updating Volume Controller Parameters: Device: 2 Name: Soekris dam 1021 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 May 31 12:25:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 12:25:02 volumio volumio[1305]: info: Disabling external Volume Control May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 12:25:02 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 12:25:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 12:25:02 volumio systemd[1]: mpd.service: Consumed 1.403s CPU time. May 31 12:25:02 volumio volumio[1305]: info: CoreStateMachine::pushState May 31 12:25:02 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 12:25:02 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioPushState May 31 12:25:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 12:25:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 12:25:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 12:25:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 12:25:02 volumio volumio[1305]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 May 31 12:25:02 volumio volumio[1305]: info: MPD Permissions set May 31 12:25:02 volumio volumio[1305]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 May 31 12:25:02 volumio volumio[1305]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 May 31 12:25:02 volumio volumio[1305]: info: CoreStateMachine::pushState May 31 12:25:02 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::volumioPushState May 31 12:25:02 volumio volumio[1305]: info: Software Volume ALSA configuration written May 31 12:25:02 volumio volumio[1305]: info: Preparing to generate the ALSA configuration file May 31 12:25:02 volumio sudo[1866]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 12:25:02 volumio sudo[1866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:02 volumio sudo[1866]: pam_unix(sudo:session): session closed for user root May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 12:25:02 volumio volumio[1305]: info: Getting Alsa Cards List without I2S DAC May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 31 12:25:02 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 12:25:03 volumio volumio[1305]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 12:25:03 volumio volumio[1305]: info: Reading ALSA contributions from plugins. May 31 12:25:03 volumio volumio[1305]: info: VolumeController:: Volume=undefined Mute =false May 31 12:25:03 volumio volumio[1305]: info: CoreStateMachine::pushState May 31 12:25:03 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::volumioPushState May 31 12:25:03 volumio volumio[1305]: info: Starting Shairport Sync May 31 12:25:03 volumio sudo[1890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 12:25:03 volumio sudo[1890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:03 volumio volumio[1305]: info: Asound.conf file written May 31 12:25:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 12:25:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 31 12:25:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:03 volumio systemd[1]: shairport-sync.service: Consumed 1.749s CPU time. May 31 12:25:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:03 volumio sudo[1890]: pam_unix(sudo:session): session closed for user root May 31 12:25:03 volumio sudo[1894]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 31 12:25:03 volumio sudo[1894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:03 volumio sudo[1894]: pam_unix(sudo:session): session closed for user root May 31 12:25:03 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 31 12:25:03 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 31 12:25:03 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 31 12:25:03 volumio volumio[1305]: info: Output device has changed, restarting MPD May 31 12:25:03 volumio volumio[1305]: info: Output device has changed, restarting Shairport Sync May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:03 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:03 volumio sudo[1915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 12:25:03 volumio sudo[1915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:03 volumio sudo[1915]: pam_unix(sudo:session): session closed for user root May 31 12:25:03 volumio sudo[1917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 12:25:03 volumio sudo[1917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:03 volumio volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 12:25:03 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 12:25:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 12:25:03 volumio systemd[1]: mpd.service: Consumed 1.129s CPU time. May 31 12:25:03 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 12:25:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 12:25:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 12:25:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 12:25:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 12:25:03 volumio sudo[1928]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 12:25:03 volumio sudo[1928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:03 volumio sudo[1928]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio volumio[1305]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo May 31 12:25:05 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 31 12:25:05 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 31 12:25:05 volumio volumio[1305]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 31 12:25:05 volumio volumio[1305]: info: Output device has changed, restarting MPD May 31 12:25:05 volumio volumio[1305]: info: Output device has changed, restarting Shairport Sync May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:05 volumio mpd[1930]: 2025-05-31T12:25:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 12:25:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 31 12:25:05 volumio sudo[1917]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio sudo[1849]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio sudo[1936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 12:25:05 volumio sudo[1936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:05 volumio volumio[1305]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 12:25:05 volumio sudo[1937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 12:25:05 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:05 volumio sudo[1936]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 12:25:05 volumio volumio[1305]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 12:25:05 volumio volumio[1305]: info: Disabling external Volume Control May 31 12:25:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 12:25:05 volumio volumio[1305]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 May 31 12:25:05 volumio volumio[1305]: info: MPD Permissions set May 31 12:25:05 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 12:25:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 12:25:05 volumio systemd[1]: mpd.service: Consumed 1.467s CPU time. May 31 12:25:05 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 12:25:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 12:25:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 12:25:05 volumio volumio[1305]: info: MPD Permissions set May 31 12:25:05 volumio volumio[1305]: info: Shairport-Sync Started May 31 12:25:05 volumio volumio[1305]: error: MPD error: Error: connect ECONNRESET /run/mpd/socket May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 12:25:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:05 volumio volumio[1305]: info: CoreStateMachine::pushState May 31 12:25:05 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 12:25:05 volumio volumio[1305]: info: CoreCommandRouter::volumioPushState May 31 12:25:05 volumio sudo[1961]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 12:25:05 volumio sudo[1961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:05 volumio sudo[1961]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio volumio[1305]: info: Starting Shairport Sync May 31 12:25:05 volumio volumio[1305]: info: Starting Shairport Sync May 31 12:25:05 volumio sudo[1971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 12:25:05 volumio sudo[1971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:05 volumio sudo[1973]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 12:25:05 volumio sudo[1973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 12:25:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 31 12:25:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:05 volumio systemd[1]: shairport-sync.service: Consumed 1.431s CPU time. May 31 12:25:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:05 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 12:25:05 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 31 12:25:05 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:05 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 12:25:05 volumio sudo[1973]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio volumio[1305]: info: Shairport-Sync Started May 31 12:25:05 volumio sudo[1971]: pam_unix(sudo:session): session closed for user root May 31 12:25:05 volumio volumio[1305]: info: Shairport-Sync Started May 31 12:25:06 volumio volumio[1305]: info: VolumeController::SetAlsaVolume0 May 31 12:25:06 volumio volumio[1305]: info: CoreStateMachine::pushState May 31 12:25:06 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:25:06 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 12:25:06 volumio volumio[1305]: info: CoreCommandRouter::volumioPushState May 31 12:25:06 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 31 12:25:07 volumio sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 12:25:07 volumio sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:07 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 12:25:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 12:25:07 volumio systemd[1]: mpd.service: Consumed 1.468s CPU time. May 31 12:25:07 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 12:25:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 12:25:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 12:25:07 volumio volumio[1305]: error: MPD error: Error: read ECONNRESET May 31 12:25:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 12:25:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 12:25:07 volumio sudo[1997]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 12:25:07 volumio sudo[1997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:07 volumio sudo[1997]: pam_unix(sudo:session): session closed for user root May 31 12:25:08 volumio mpd[1999]: 2025-05-31T12:25:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 12:25:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 31 12:25:08 volumio sudo[1994]: pam_unix(sudo:session): session closed for user root May 31 12:25:08 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root May 31 12:25:08 volumio volumio[1305]: error: MPD error: The expression evaluated to a falsy value: May 31 12:25:08 volumio volumio[1305]: assert.ok(self.idling) May 31 12:25:08 volumio volumio[1305]: error: The expression evaluated to a falsy value: May 31 12:25:08 volumio volumio[1305]: assert.ok(self.idling) May 31 12:25:08 volumio volumio[1305]: error: updateQueue error: null May 31 12:25:08 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 31 12:25:08 volumio dbus-daemon[673]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.32' (uid=0 pid=2003 comm="timedatectl show --property=NTPSynchronized --valu") May 31 12:25:08 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 31 12:25:09 volumio dbus-daemon[673]: [system] Successfully activated service 'org.freedesktop.timedate1' May 31 12:25:09 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 31 12:25:09 volumio setdatetime-helper.sh[2002]: Time is not synchronized. Attempting to sync... May 31 12:25:09 volumio sudo[2011]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sat, 31 May 2025 04:25:09 GMT#015' May 31 12:25:09 volumio sudo[2011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:09 volumio setdatetime-helper.sh[2012]: Sat May 31 12:25:09 CST 2025 May 31 12:25:09 volumio sudo[2011]: pam_unix(sudo:session): session closed for user root May 31 12:25:09 volumio setdatetime-helper.sh[2002]: Time synchronized successfully. May 31 12:25:09 volumio systemd-journald[355]: Time jumped backwards, rotating. May 31 12:25:09 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 31 12:25:09 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 31 12:25:10 volumio volumio[1305]: error: updateQueue error: null May 31 12:25:11 volumio volumio[1305]: error: updateQueue error: null May 31 12:25:32 volumio volumio[1305]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 31 12:25:32 volumio sudo[2058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 12:25:32 volumio sudo[2058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:32 volumio sudo[2058]: pam_unix(sudo:session): session closed for user root May 31 12:25:32 volumio volumio[1305]: info: MPD Permissions set May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio sudo[2060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 12:25:32 volumio sudo[2060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 12:25:32 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 12:25:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 12:25:32 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 12:25:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 12:25:32 volumio systemd[1]: mpd.service: Consumed 1.405s CPU time. May 31 12:25:32 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 12:25:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 12:25:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 12:25:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 12:25:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 12:25:32 volumio sudo[2069]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 12:25:32 volumio sudo[2069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:25:32 volumio sudo[2069]: pam_unix(sudo:session): session closed for user root May 31 12:25:34 volumio mpd[2071]: 2025-05-31T12:25:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 12:25:34 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 31 12:25:34 volumio sudo[2060]: pam_unix(sudo:session): session closed for user root May 31 12:25:34 volumio volumio[1305]: error: updateQueue error: null May 31 12:25:38 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 31 12:26:11 volumio volumio[1305]: info: CoreCommandRouter::volumioGetState May 31 12:26:11 volumio volumio[1305]: info: CorePlayQueue::getTrack 0 May 31 12:26:11 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 31 12:26:12 volumio dbus-daemon[673]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.34' (uid=0 pid=2150 comm="timedatectl show --property=NTPSynchronized --valu") May 31 12:26:12 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 31 12:26:12 volumio dbus-daemon[673]: [system] Successfully activated service 'org.freedesktop.timedate1' May 31 12:26:12 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 31 12:26:12 volumio setdatetime-helper.sh[2136]: Time is not synchronized. Attempting to sync... May 31 12:26:12 volumio sudo[2159]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sat, 31 May 2025 04:26:13 GMT#015' May 31 12:26:12 volumio sudo[2159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 12:26:13 volumio setdatetime-helper.sh[2160]: Sat May 31 12:26:13 CST 2025 May 31 12:26:13 volumio sudo[2159]: pam_unix(sudo:session): session closed for user root May 31 12:26:13 volumio setdatetime-helper.sh[2136]: Time synchronized successfully. May 31 12:26:13 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 31 12:26:13 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 31 12:26:26 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 31 12:26:26 volumio volumio[1305]: info: CURURI: music-library May 31 12:26:26 volumio volumio[1305]: info: Preload queue cleared May 31 12:26:28 volumio volumio[1305]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 31 12:26:28 volumio volumio[1305]: info: CURURI: music-library/USB May 31 12:26:28 volumio volumio[1305]: info: Preload queue cleared May 31 12:26:32 volumio volumio[1305]: info: Preload queue cleared May 31 12:26:32 volumio volumio[1305]: info: CoreCommandRouter::volumioReplaceandPlayItems May 31 12:26:32 volumio volumio[1305]: info: CoreStateMachine::ClearQueue May 31 12:26:32 volumio volumio[1305]: info: CoreStateMachine::stop May 31 12:26:32 volumio volumio[1305]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 12:26:32 volumio volumio[1305]: info: CorePlayQueue::clearPlayQueue May 31 12:26:32 volumio volumio[1305]: info: CorePlayQueue::saveQueue May 31 12:26:32 volumio volumio[1305]: info: CoreCommandRouter::volumioPushQueue May 31 12:26:32 volumio volumio[1305]: info: CoreStateMachine::addQueueItems May 31 12:26:32 volumio volumio[1305]: info: CorePlayQueue::addQueueItems May 31 12:26:32 volumio volumio[1305]: info: Preload queue cleared May 31 12:26:32 volumio volumio[1305]: info: Adding Item to queue: music-library/USB/SP_UFD_U3 May 31 12:26:32 volumio volumio[1305]: info: Exploding uri music-library/USB/SP_UFD_U3 in service mpd May 31 12:26:32 volumio volumio[1305]: info: ALBUMART /albumart?cacheid=228&web=Alborada/Five%20Spirits/extralarge&path=%2Fmnt%2FUSB%2FSP_UFD_U3%2FApache%20-%20Five%20Spirits%2F00%20-%20Alborada%20-%20Five%20Spirits.cue&metadata=false May 31 12:26:32 volumio volumio[1305]: info: URI /mnt/USB/SP_UFD_U3/Apache - Five Spirits/00 - Alborada - Five Spirits.cue May 31 12:26:32 volumio volumio[1305]: info: ALBUMART /albumart?cacheid=228&web=Alborada/Five%20Spirits/extralarge&path=%2Fmnt%2FUSB%2FSP_UFD_U3%2FApache%20-%20Five%20Spirits%2F00%20-%20Alborada%20-%20Five%20Spirits.cue&metadata=false May 31 12:26:32 volumio volumio[1305]: info: URI /mnt/USB/SP_UFD_U3/Apache - Five Spirits/00 - Alborada - Five Spirits.cue May 31 12:26:32 volumio volumio[1305]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 12:26:32 volumio volumio[1305]: Error: Unable to resolve or reject the same promise twice May 31 12:26:32 volumio volumio[1305]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 31 12:26:32 volumio volumio[1305]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 May 31 12:26:32 volumio volumio[1305]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 31 12:26:32 volumio volumio[1305]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 31 12:26:32 volumio volumio[1305]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 31 12:26:32 volumio volumio[1305]: at Socket.emit (node:events:514:28) May 31 12:26:32 volumio volumio[1305]: at addChunk (node:internal/streams/readable:343:12) May 31 12:26:32 volumio volumio[1305]: at readableAddChunk (node:internal/streams/readable:312:11) May 31 12:26:32 volumio volumio[1305]: at Readable.push (node:internal/streams/readable:253:10) May 31 12:26:32 volumio volumio[1305]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) May 31 12:26:32 volumio volumio[1305]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 12:26:34 volumio sudo[2205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-31 12:25' May 31 12:26:34 volumio sudo[2205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="1da895bfdbb6eb90d965df32a25a3568df7c84ed" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu May 29 13:12:59 UTC 2025" VOLUMIO_VERSION="4.004" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2df63d74196e499fa1e34fb765df1cca"