Oct 16 15:07:24 volprox go-librespot[1466]: time="2025-10-16T15:07:24+09:00" level=trace msg="received accesspoint ping" Oct 16 15:07:24 volprox go-librespot[1466]: time="2025-10-16T15:07:24+09:00" level=trace msg="received accesspoint pong ack" Oct 16 15:07:25 volprox go-librespot[1466]: time="2025-10-16T15:07:25+09:00" level=trace msg="sent dealer ping" Oct 16 15:07:25 volprox go-librespot[1466]: time="2025-10-16T15:07:25+09:00" level=trace msg="received dealer pong" Oct 16 15:07:55 volprox go-librespot[1466]: time="2025-10-16T15:07:55+09:00" level=trace msg="sent dealer ping" Oct 16 15:07:55 volprox go-librespot[1466]: time="2025-10-16T15:07:55+09:00" level=trace msg="received dealer pong" Oct 16 15:08:16 volprox volumio[977]: info: [yt-cast-receiver] Player.pause() Oct 16 15:08:16 volprox volumio[977]: info: Ignoring MPD Status Update Oct 16 15:08:16 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:16 volprox volumio[977]: info: CoreCommandRouter::servicePushState Oct 16 15:08:16 volprox volumio[977]: info: CoreStateMachine::pushState Oct 16 15:08:16 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 15:08:16 volprox volumio[977]: info: CoreCommandRouter::volumioPushState Oct 16 15:08:16 volprox volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 16 15:08:21 volprox volumio[977]: verbose: New Socket.io Connection to 172.30.1.20 from 172.30.1.56 UA: Mozilla/5.0 (Linux; Android 16; SM-F766N Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.207 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 16 15:08:21 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:21 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:21 volprox volumio[977]: info: Discovery: Getting this device information Oct 16 15:08:21 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:21 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:21 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 15:08:22 volprox volumio[977]: info: Received Get System Info Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:22 volprox volumio[977]: info: Discovery: Getting this device information Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:22 volprox volumio[977]: info: Listing playlists Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetQueue Oct 16 15:08:22 volprox volumio[977]: info: CoreStateMachine::getQueue Oct 16 15:08:22 volprox volumio[977]: info: CorePlayQueue::getQueue Oct 16 15:08:22 volprox volumio[977]: verbose: New Socket.io Connection to 172.30.1.20:3000 from 172.30.1.56 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 15:08:22 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 15:08:24 volprox volumio[977]: info: Received Get System Info Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:24 volprox volumio[977]: info: Discovery: Getting this device information Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:24 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 16 15:08:25 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 16 15:08:25 volprox go-librespot[1466]: time="2025-10-16T15:08:25+09:00" level=trace msg="sent dealer ping" Oct 16 15:08:25 volprox go-librespot[1466]: time="2025-10-16T15:08:25+09:00" level=trace msg="received dealer pong" Oct 16 15:08:26 volprox volumio[977]: verbose: New Socket.io Connection to 172.30.1.20:3000 from 172.30.1.56 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 16 15:08:27 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 15:08:27 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 15:08:27 volprox volumio[977]: info: Discovery: Getting this device information Oct 16 15:08:27 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:27 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 15:08:32 volprox volumio[977]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:32 volprox volumio[977]: info: Restoring Previous Volume level: 100 false false Oct 16 15:08:32 volprox volumio[977]: info: Output device has changed, restarting MPD Oct 16 15:08:32 volprox volumio[977]: info: Output device has changed, restarting Shairport Sync Oct 16 15:08:32 volprox sudo[75724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 15:08:32 volprox sudo[75724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 15:08:32 volprox sudo[75724]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:32 volprox sudo[75726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 15:08:32 volprox sudo[75726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 15:08:32 volprox volumio[977]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 15:08:32 volprox volumio[977]: info: Volume configurations have been set Oct 16 15:08:32 volprox systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 16 15:08:32 volprox volumio[977]: info: Updating Volume Controller Parameters: Device: 5 Name: USB HIFI Audio Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 16 15:08:32 volprox volumio[977]: info: Disabling external Volume Control Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::volumioGetState Oct 16 15:08:32 volprox volumio[977]: info: CoreStateMachine::pushState Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 15:08:32 volprox volumio[977]: info: CoreCommandRouter::volumioPushState Oct 16 15:08:32 volprox volumio[977]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 15:08:32 volprox volumio[977]: MPDError: Not connected Oct 16 15:08:32 volprox volumio[977]: at MPDClient.send (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:100:13) Oct 16 15:08:32 volprox volumio[977]: at MPDClient.sendCommand (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:64:10) Oct 16 15:08:32 volprox volumio[977]: at Object.get (/data/plugins/music_service/ytcr/node_modules/mpd-api/lib/api/index.js:60:16) Oct 16 15:08:32 volprox volumio[977]: at MPDPlayer.getVolumioState (/data/plugins/music_service/ytcr/dist/lib/MPDPlayer.js:297:100) Oct 16 15:08:32 volprox volumio[977]: at ControllerYTCR.pushState (/data/plugins/music_service/ytcr/dist/index.js:482:103) Oct 16 15:08:32 volprox volumio[977]: at /data/plugins/music_service/ytcr/dist/index.js:292:28 Oct 16 15:08:32 volprox volumio[977]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) Oct 16 15:08:32 volprox volumio[977]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) Oct 16 15:08:32 volprox volumio[977]: at Promise._successFn (/volumio/app/volumecontrol.js:485:30) Oct 16 15:08:32 volprox volumio[977]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 16 15:08:32 volprox volumio[977]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Oct 16 15:08:32 volprox volumio[977]: code: 'ENOTCONNECTED' Oct 16 15:08:32 volprox volumio[977]: } Oct 16 15:08:32 volprox volumio[977]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 15:08:32 volprox systemd[1]: mpd.service: Deactivated successfully. Oct 16 15:08:32 volprox systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 15:08:32 volprox systemd[1]: mpd.service: Consumed 8.826s CPU time. Oct 16 15:08:32 volprox systemd[1]: mpd.socket: Deactivated successfully. Oct 16 15:08:32 volprox systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 15:08:32 volprox systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 15:08:32 volprox systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 15:08:32 volprox systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 15:08:32 volprox sudo[75750]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 15:08:32 volprox sudo[75750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 15:08:32 volprox sudo[75750]: pam_unix(sudo:session): session closed for user root Oct 16 15:08:32 volprox sudo[75753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-16 15:07' Oct 16 15:08:32 volprox sudo[75753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7840f283c310c38bfe939a4c485727a6ff6a0ce1" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Oct 9 18:33:08 UTC 2025" VOLUMIO_VERSION="4.062" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="434a4f7d2e5f6acafabfcca26b8e5834"