Jun 29 23:08:06 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioGetState Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jun 29 23:08:10 volumio-speaker volumio[869]: info: Received Get System Version Jun 29 23:08:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 29 23:08:15 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioGetState Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 29 23:08:17 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 29 23:08:57 volumio-speaker systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 29 23:08:57 volumio-speaker systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Jun 29 23:08:57 volumio-speaker systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Jun 29 23:08:57 volumio-speaker systemd[1]: welcome.service: Deactivated successfully. Jun 29 23:08:57 volumio-speaker systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 29 23:08:57 volumio-speaker systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 29 23:08:57 volumio-speaker systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 29 23:08:57 volumio-speaker dbus-daemon[561]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.275' (uid=0 pid=18813 comm="timedatectl show --property=NTPSynchronized --valu") Jun 29 23:08:57 volumio-speaker welcome[18815]: Resolved ip:[1] 192.168.0.64 Jun 29 23:08:57 volumio-speaker systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 29 23:08:57 volumio-speaker systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 29 23:08:57 volumio-speaker systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jun 29 23:08:57 volumio-speaker dbus-daemon[561]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 29 23:08:57 volumio-speaker systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 29 23:08:57 volumio-speaker setdatetime-helper.sh[18807]: Time is already synchronized. Jun 29 23:08:57 volumio-speaker systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 29 23:08:57 volumio-speaker systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 29 23:09:10 volumio-speaker volumio[869]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioGetState Jun 29 23:09:10 volumio-speaker volumio[869]: info: Restoring Previous Volume level: 31 false true Jun 29 23:09:10 volumio-speaker volumio[869]: info: VolumeController::SetAlsaVolume100 Jun 29 23:09:10 volumio-speaker volumio[869]: info: Enable softmixer device for audio device number 5 Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioStop Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreStateMachine::stop Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreStateMachine::serviceStop Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::serviceStop Jun 29 23:09:10 volumio-speaker volumio[869]: info: [yt-cast-receiver] Player.stop() Jun 29 23:09:10 volumio-speaker volumio[869]: info: Enable softmixer device for audio device undefined Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 29 23:09:10 volumio-speaker volumio[869]: info: Updating Volume Controller Parameters: Device: 5 Name: Combo384 Amanero Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 29 23:09:10 volumio-speaker volumio[869]: info: Disabling external Volume Control Jun 29 23:09:10 volumio-speaker volumio[869]: info: Output device has changed, restarting MPD Jun 29 23:09:10 volumio-speaker volumio[869]: info: Output device has changed, restarting Shairport Sync Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 29 23:09:10 volumio-speaker volumio[869]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 29 23:09:10 volumio-speaker volumio[869]: info: Volume configurations have been set Jun 29 23:09:10 volumio-speaker sudo[18856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 29 23:09:10 volumio-speaker sudo[18856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 29 23:09:10 volumio-speaker sudo[18858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 29 23:09:10 volumio-speaker sudo[18858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 29 23:09:10 volumio-speaker sudo[18856]: pam_unix(sudo:session): session closed for user root Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 29 23:09:10 volumio-speaker volumio[869]: info: Updating Volume Controller Parameters: Device: 5 Name: Combo384 Amanero Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 29 23:09:10 volumio-speaker volumio[869]: info: Disabling external Volume Control Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 29 23:09:10 volumio-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioGetState Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreStateMachine::pushState Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioPushState Jun 29 23:09:10 volumio-speaker volumio[869]: info: MPD Permissions set Jun 29 23:09:10 volumio-speaker volumio[869]: info: Software Volume ALSA configuration written Jun 29 23:09:10 volumio-speaker volumio[869]: info: Preparing to generate the ALSA configuration file Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioGetState Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreStateMachine::pushState Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 23:09:10 volumio-speaker volumio[869]: info: CoreCommandRouter::volumioPushState Jun 29 23:09:10 volumio-speaker volumio[869]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 29 23:09:10 volumio-speaker volumio[869]: MPDError: Not connected Jun 29 23:09:10 volumio-speaker volumio[869]: at MPDClient.send (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:100:13) Jun 29 23:09:10 volumio-speaker volumio[869]: at MPDClient.sendCommand (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:64:10) Jun 29 23:09:10 volumio-speaker volumio[869]: at Object.get (/data/plugins/music_service/ytcr/node_modules/mpd-api/lib/api/index.js:60:16) Jun 29 23:09:10 volumio-speaker volumio[869]: at MPDPlayer.getVolumioState (/data/plugins/music_service/ytcr/dist/lib/MPDPlayer.js:297:100) Jun 29 23:09:10 volumio-speaker volumio[869]: at ControllerYTCR.pushState (/data/plugins/music_service/ytcr/dist/index.js:482:103) Jun 29 23:09:10 volumio-speaker volumio[869]: at /data/plugins/music_service/ytcr/dist/index.js:292:28 Jun 29 23:09:10 volumio-speaker volumio[869]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) Jun 29 23:09:10 volumio-speaker volumio[869]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) Jun 29 23:09:10 volumio-speaker volumio[869]: at Promise._successFn (/volumio/app/volumecontrol.js:505:34) Jun 29 23:09:10 volumio-speaker volumio[869]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 29 23:09:10 volumio-speaker volumio[869]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Jun 29 23:09:10 volumio-speaker volumio[869]: code: 'ENOTCONNECTED' Jun 29 23:09:10 volumio-speaker volumio[869]: } Jun 29 23:09:10 volumio-speaker volumio[869]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 29 23:09:10 volumio-speaker systemd[1]: mpd.service: Deactivated successfully. Jun 29 23:09:10 volumio-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Jun 29 23:09:10 volumio-speaker systemd[1]: mpd.service: Consumed 3min 32.346s CPU time. Jun 29 23:09:10 volumio-speaker systemd[1]: mpd.socket: Deactivated successfully. Jun 29 23:09:10 volumio-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jun 29 23:09:10 volumio-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jun 29 23:09:10 volumio-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jun 29 23:09:10 volumio-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Jun 29 23:09:10 volumio-speaker sudo[18892]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 29 23:09:10 volumio-speaker sudo[18892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 29 23:09:11 volumio-speaker sudo[18892]: pam_unix(sudo:session): session closed for user root Jun 29 23:09:11 volumio-speaker sudo[18897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-29 23:08' Jun 29 23:09:11 volumio-speaker sudo[18897]: 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="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:09:10 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f9bd4447a30d4b2c74b3880e7a50e48b"