-- Logs begin at Fri 2025-12-12 02:47:33 JST, end at Tue 2025-12-30 14:15:18 JST. -- Dec 30 14:15:09 jbl-4312 systemd-timedated[8222]: Changed local time to Tue Dec 30 14:15:09 2025 Dec 30 14:15:09 jbl-4312 sudo[8220]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:09 jbl-4312 volumio-time-update[2841]: volumio-time-update-util: System time updated successfully. Dec 30 14:15:09 jbl-4312 systemd[1]: Started Volumio Time Update Utility. Dec 30 14:15:09 jbl-4312 systemd[1]: Starting Daily man-db regeneration... Dec 30 14:15:09 jbl-4312 systemd[1]: Reached target Multi-User System. Dec 30 14:15:09 jbl-4312 systemd[1]: Reached target Graphical Interface. Dec 30 14:15:09 jbl-4312 volumio[8050]: info: Loading plugin "qobuz"... Dec 30 14:15:09 jbl-4312 systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 30 14:15:09 jbl-4312 systemd[1]: Starting Daily apt download activities... Dec 30 14:15:09 jbl-4312 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 30 14:15:09 jbl-4312 systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 30 14:15:09 jbl-4312 systemd[1]: man-db.service: Succeeded. Dec 30 14:15:09 jbl-4312 systemd[1]: Started Daily man-db regeneration. Dec 30 14:15:09 jbl-4312 ntpd[8182]: Soliciting pool server 129.250.35.250 Dec 30 14:15:09 jbl-4312 ntpd[8182]: Soliciting pool server 162.159.200.123 Dec 30 14:15:09 jbl-4312 ntpd[8182]: Soliciting pool server 85.121.50.82 Dec 30 14:15:09 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:09.823+09:00 level=INFO msg="new address was allocated" component=conn/ble old=96 new=97 Dec 30 14:15:10 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:10.207+09:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:59542->127.0.0.1:3000: i/o timeout" Dec 30 14:15:10 jbl-4312 dbus-daemon[2832]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.8" (uid=0 pid=3333 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=3196 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Dec 30 14:15:10 jbl-4312 ntpd[8182]: Soliciting pool server 45.76.211.39 Dec 30 14:15:10 jbl-4312 ntpd[8182]: Soliciting pool server 5.104.87.198 Dec 30 14:15:10 jbl-4312 volumio[8050]: info: Plugin smart_inputs is not enabled Dec 30 14:15:10 jbl-4312 volumio[8050]: info: Loading plugin "tidal"... Dec 30 14:15:10 jbl-4312 dbus-daemon[2832]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.8" (uid=0 pid=3333 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=3196 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Dec 30 14:15:11 jbl-4312 systemd[1]: apt-daily.service: Succeeded. Dec 30 14:15:11 jbl-4312 systemd[1]: Started Daily apt download activities. Dec 30 14:15:11 jbl-4312 systemd[1]: Starting Daily apt upgrade and clean activities... Dec 30 14:15:11 jbl-4312 ntpd[8182]: Soliciting pool server 122.215.240.52 Dec 30 14:15:11 jbl-4312 volumio[8050]: info: Loading plugin "rivopluscontrol"... Dec 30 14:15:11 jbl-4312 volumio[8050]: info: Adding this device properties Dec 30 14:15:11 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Dec 30 14:15:11 jbl-4312 volumio[8050]: info: Setting Additional Device Volumio Properties: [object Object] Dec 30 14:15:11 jbl-4312 volumio[8050]: info: Loading plugin "updater_comm"... Dec 30 14:15:11 jbl-4312 volumio[8050]: info: Loading plugin "cec_controller"... Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Applying required configuration parameters for plugin cec_controller Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Plugin mpdemulation is not enabled Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Loading plugin "rest_api"... Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Loading plugin "websocket"... Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Starting Socket.io Server version 2.3.0 Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Loading plugin "fusiondsp"... Dec 30 14:15:12 jbl-4312 ntpd[8182]: Soliciting pool server 153.127.38.46 Dec 30 14:15:12 jbl-4312 ntpd[8182]: Soliciting pool server 142.91.108.61 Dec 30 14:15:12 jbl-4312 ntpd[8182]: Soliciting pool server 240b:4009:272:9c06:def8:1b59:32ba:155f Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Applying required configuration parameters for plugin fusiondsp Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Loading i18n strings for locale ja Dec 30 14:15:12 jbl-4312 volumio[8050]: Updating browse sources language Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::initPlayerControls Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: Express server listening on port 3000 Dec 30 14:15:12 jbl-4312 volumio[8050]: [Metrics] WebUI: 12s 712.52ms Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreStateMachine::resetVolumioState Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreStateMachine::getcurrentVolume Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 14:15:12 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:12 jbl-4312 volumio[8050]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Completed loading Core Plugins Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Preparing to generate the ALSA configuration file Dec 30 14:15:12 jbl-4312 volumio[8050]: info: Cannot read play queue from file Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Volumio Network Manager: Network status updated: 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Dec 30 14:15:13 jbl-4312 volumio[8050]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Reading ALSA contributions from plugins. Dec 30 14:15:13 jbl-4312 systemd[1]: apt-daily-upgrade.service: Succeeded. Dec 30 14:15:13 jbl-4312 systemd[1]: Started Daily apt upgrade and clean activities. Dec 30 14:15:13 jbl-4312 systemd[1]: Startup finished in 13.034s (kernel) + 4min 31.802s (userspace) = 4min 44.836s. Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Dec 30 14:15:13 jbl-4312 volumio[8050]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SMSL USB AUDIO ',0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: Getting this device information Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: Getting this device information Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Volumio Network Manager: Network status updated: 1 Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Dec 30 14:15:13 jbl-4312 ntpd[8182]: Soliciting pool server 172.105.192.74 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: VolumeController:: Volume=undefined Mute =false Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::updateTrackBlock Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrackBlock Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::setRepeat null single undefined Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::setRandom null Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to 192.168.3.4:3000 from 192.168.3.13 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 1 Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 30 14:15:13 jbl-4312 volumio[8050]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SMSL USB AUDIO ',0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: adding 477e6b25-e4ef-4cfb-b828-303619ebc483 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: Found device JBL 4312 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Dec 30 14:15:13 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Received Get System Info Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: Getting this device information Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Received Get System Info Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Discovery: Getting this device information Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 14:15:13 jbl-4312 volumio[8050]: info: VolumeController:: Volume=undefined Mute =false Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Asound.conf file unchanged, so no further update is needed Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Output device has changed, restarting MPD Dec 30 14:15:13 jbl-4312 sudo[8381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 14:15:13 jbl-4312 sudo[8381]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 volumio[8050]: info: ___________ START PLUGINS ___________ Dec 30 14:15:13 jbl-4312 sudo[8381]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:13 jbl-4312 sudo[8383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 14:15:13 jbl-4312 sudo[8383]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 volumio[8050]: info: ControllerMpd::onStart: Initializing MPD Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Creating MPD Configuration file Dec 30 14:15:13 jbl-4312 systemd[1]: Stopping Music Player Daemon... Dec 30 14:15:13 jbl-4312 sudo[8387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Dec 30 14:15:13 jbl-4312 sudo[8387]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 sudo[8390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 14:15:13 jbl-4312 sudo[8390]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 14:15:13 jbl-4312 volumio[8050]: info: [1767071713722] CoreMusicLibrary::Adding element Last_100 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 14:15:13 jbl-4312 sudo[8387]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:13 jbl-4312 sudo[8390]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Streaming services startup Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Starting Streaming Daemon Dec 30 14:15:13 jbl-4312 systemd[1]: mpd.service: Succeeded. Dec 30 14:15:13 jbl-4312 systemd[1]: Stopped Music Player Daemon. Dec 30 14:15:13 jbl-4312 sudo[8392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 14:15:13 jbl-4312 sudo[8392]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 systemd[1]: Starting Music Player Daemon... Dec 30 14:15:13 jbl-4312 sudo[8397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 30 14:15:13 jbl-4312 sudo[8397]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:13 jbl-4312 sudo[8397]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 14:15:13 jbl-4312 volumio[8050]: info: [1767071713826] CoreMusicLibrary::Adding element Webradio Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Initializing BBC Radios Dec 30 14:15:13 jbl-4312 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Dec 30 14:15:13 jbl-4312 systemd[1]: mpd.service: Succeeded. Dec 30 14:15:13 jbl-4312 systemd[1]: Stopped Music Player Daemon. Dec 30 14:15:13 jbl-4312 systemd[1]: Starting Music Player Daemon... Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Creating Spotify config file Dec 30 14:15:13 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:13 jbl-4312 volumio[8050]: error: Hi Res Audio Failed Login: Missing Login Data Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Initializing Serial Communication on port /dev/ttyS3 Dec 30 14:15:13 jbl-4312 kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 115200 to 115200 Dec 30 14:15:13 jbl-4312 volumio[8050]: info: Touch Event Listener Process Starting Dec 30 14:15:14 jbl-4312 sudo[8416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Dec 30 14:15:14 jbl-4312 sudo[8405]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 14:15:14 jbl-4312 sudo[8416]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8405]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8405]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 sudo[8416]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 sudo[8423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Dec 30 14:15:14 jbl-4312 sudo[8423]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8423]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 sudo[8426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Dec 30 14:15:14 jbl-4312 sudo[8426]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8426]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 sudo[8429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Dec 30 14:15:14 jbl-4312 sudo[8429]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8429]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 sudo[8432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Dec 30 14:15:14 jbl-4312 sudo[8432]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 sudo[8432]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Apply VIM3L Onboard LEDs Settings Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Turning On Onboard LEDs Dec 30 14:15:14 jbl-4312 sudo[8436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Dec 30 14:15:14 jbl-4312 sudo[8436]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Starting CEC Event listener Dec 30 14:15:14 jbl-4312 sudo[8436]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Loading i18n strings for locale ja Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:14 jbl-4312 sudo[8440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Dec 30 14:15:14 jbl-4312 sudo[8440]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:14 jbl-4312 volumio[8050]: info: FusionDsp - mixtype--------------------- Hardware Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Volumio Calling Home Dec 30 14:15:14 jbl-4312 sudo[8440]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:14 jbl-4312 ntpd[8182]: Soliciting pool server 45.77.20.103 Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Preparing to generate the ALSA configuration file Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Stopping AccessToken refresher cron for QOBUZ Dec 30 14:15:14 jbl-4312 volumio[8050]: info: AccessToken refresher cron started for QOBUZ Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Adding TIDAL REST API Endpoints Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Adding QOBUZ REST API Endpoints Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Discovery: A device disappeared from network Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 30 14:15:14 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:14.725+09:00 level=INFO msg="BLE descriptor updated" deviceId=22366d4cda9f547124971b6f96d9907a deviceName="JBL 4312" deviceModel=0x1d028f0 Dec 30 14:15:14 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:14.737+09:00 level=INFO msg="mDNS descriptor updated" deviceId=22366d4cda9f547124971b6f96d9907a deviceName="JBL 4312" deviceModel=0x1d028f0 Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Serial port opened successfully Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Sending serial start messages Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Reporting MCU Network Status: 1 Dec 30 14:15:14 jbl-4312 volumio[8050]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Reading ALSA contributions from plugins. Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:14 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 30 14:15:14 jbl-4312 volumio[8050]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Dec 30 14:15:14 jbl-4312 volumio[8050]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Dec 30 14:15:14 jbl-4312 volumio[8050]: info: Touch Event Listener Process Closed Dec 30 14:15:15 jbl-4312 volumio[8050]: error: Cannot start Volumio Streaming Daemon Dec 30 14:15:15 jbl-4312 volumio[8050]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 30 14:15:15 jbl-4312 volumio[8050]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MPD Permissions set Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MPD Permissions set Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting Device Volume Override Dec 30 14:15:15 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:15.073+09:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.3.13:59410 @ 0x1d3e780" latency=-443h23m10.424880944s timeout=10s error="failed to get output devices: could not get extended output devices: context deadline exceeded" Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Updating Volume Controller Parameters: Device: 5 Name: SMSL USB AUDIO Mixer: SMSL USB AUDIO Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Disabling external Volume Control Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:15 jbl-4312 volumio[8050]: amixer -c 5 info | grep "SMSL USB AUDIO" Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Volumio called home Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Spotify config file written Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting Additional System Software info: Hardware Revision: 1.0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting HW Firmware info: undefined Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting HW Version info: 1.0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting Additional System Software info: Hardware Revision: 1.0, Firmware Version: 0.3.0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting HW Firmware info: 0.3.0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Setting HW Version info: 1.0 Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MCU Signalled Headphone Mode Disabled Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MCU Signalled Sleep Mode Disabled Dec 30 14:15:15 jbl-4312 sudo[8468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 14:15:15 jbl-4312 sudo[8468]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Enabling Advanced system settings configuration Dec 30 14:15:15 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Dec 30 14:15:15 jbl-4312 volumio[8050]: info: Additional UI Settings Added for plugin music_service/inputs Dec 30 14:15:15 jbl-4312 volumio[8050]: info: MCU Signalled Auto Boot Mode On Power Disabled Dec 30 14:15:15 jbl-4312 systemd[1]: Stopping go-librespot Daemon... Dec 30 14:15:15 jbl-4312 systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Dec 30 14:15:15 jbl-4312 systemd[1]: go-librespot-daemon.service: Succeeded. Dec 30 14:15:15 jbl-4312 systemd[1]: Stopped go-librespot Daemon. Dec 30 14:15:15 jbl-4312 systemd[1]: Started go-librespot Daemon. Dec 30 14:15:15 jbl-4312 sudo[8471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Dec 30 14:15:15 jbl-4312 sudo[8471]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:15 jbl-4312 sudo[8468]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:16 jbl-4312 ntpd[8182]: receive: Unexpected origin timestamp 0xecfdde63.614add44 does not match aorg 0000000000.00000000 from server@5.104.87.198 xmt 0xecfdde64.e008e306 Dec 30 14:15:16 jbl-4312 sudo[8471]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:16 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 30 14:15:16 jbl-4312 go-librespot[8472]: go-librespot daemon starting... Dec 30 14:15:16 jbl-4312 volumio[8050]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SMSL USB AUDIO ',0 Dec 30 14:15:16 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:16+09:00" level=info msg="running go-librespot 0.4.0" Dec 30 14:15:16 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:16+09:00" level=debug msg="app state loaded" Dec 30 14:15:16 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:16+09:00" level=debug msg="stored credentials not found" Dec 30 14:15:16 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:16+09:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 14:15:16 jbl-4312 ntpd[8182]: Soliciting pool server 199.189.156.6 Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:16 jbl-4312 ntpd[8182]: receive: Unexpected origin timestamp 0xecfdde63.614d916c does not match aorg 0000000000.00000000 from server@194.0.5.123 xmt 0xecfdde64.ebd1362e Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:16 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: No need to fix Spotify hosts Dec 30 14:15:17 jbl-4312 volumio[8050]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Dec 30 14:15:17 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 30 14:15:17 jbl-4312 volumio-remote-updater[2845]: [2025-12-30 14:15:17] [connect] Successful connection Dec 30 14:15:17 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:17+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 14:15:17 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:17+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 14:15:17 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:17+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 14:15:17 jbl-4312 go-librespot[8472]: time="2025-12-30T14:15:17+09:00" level=info msg="zeroconf server listening on port 33367" Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Discovery: adding 477e6b25-e4ef-4cfb-b828-303619ebc483 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Discovery: Found device JBL 4312 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: MP1 GPIO: Signalled system ready via GPIO Dec 30 14:15:17 jbl-4312 sudo[8495]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Dec 30 14:15:17 jbl-4312 sudo[8495]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:17 jbl-4312 sudo[8495]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:17 jbl-4312 volumio5-onboarding[3333]: time=2025-12-30T14:15:17.309+09:00 level=INFO msg="new address was allocated" component=conn/ble old=97 new=98 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: VolumeController:: Volume=undefined Mute =false Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:17 jbl-4312 volumio-remote-updater[2845]: [2025-12-30 14:15:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1767071717 101 Dec 30 14:15:17 jbl-4312 volumio[8050]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Adding Inputs via Serial API Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Adding Advanced Audio Settings via Serial API Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Additional UI Settings Added for plugin music_service/inputs Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioGetState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Asound.conf file unchanged, so no further update is needed Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Output device has changed, restarting MPD Dec 30 14:15:17 jbl-4312 sudo[8498]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 sudo[8498]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:17 jbl-4312 sudo[8498]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:17 jbl-4312 sudo[8500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 14:15:17 jbl-4312 sudo[8500]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::servicePushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: verbose: STATE SERVICE {"status":"stop","service":"inputs","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"","seek":0,"duration":0,"samplerate":"","bitdepth":"","stream":true,"disableUiControls":false,"channels":2} Dec 30 14:15:17 jbl-4312 volumio[8050]: verbose: CURRENT POSITION 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::syncState stateService stop Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::syncState currentStatus stop Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: No code Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreStateMachine::pushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CorePlayQueue::getTrack 0 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumioPushState Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::volumiosetSourceActiveno-source Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 14:15:17 jbl-4312 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 30 14:15:17 jbl-4312 systemd[1]: mpd.service: Succeeded. Dec 30 14:15:17 jbl-4312 systemd[1]: Stopped Music Player Daemon. Dec 30 14:15:17 jbl-4312 systemd[1]: Starting Music Player Daemon... Dec 30 14:15:17 jbl-4312 volumio[8050]: info: MPD Permissions set Dec 30 14:15:17 jbl-4312 dbus-daemon[2832]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.8" (uid=0 pid=3333 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=3196 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: info: MCU Signalled Playback Inactive Dec 30 14:15:17 jbl-4312 sudo[8503]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 14:15:17 jbl-4312 sudo[8503]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:17 jbl-4312 sudo[8503]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:17 jbl-4312 volumio[8050]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Dec 30 14:15:17 jbl-4312 volumio[8050]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Dec 30 14:15:17 jbl-4312 volumio[8050]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Dec 30 14:15:17 jbl-4312 volumio[8050]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Dec 30 14:15:17 jbl-4312 volumio[8050]: info: camilladsp service started and running in background, instance 1 Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 14:15:17 jbl-4312 volumio[8050]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Dec 30 14:15:17 jbl-4312 volumio[8050]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Dec 30 14:15:17 jbl-4312 volumio[8050]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Dec 30 14:15:17 jbl-4312 volumio[8050]: info: FusionDsp loaded Dec 30 14:15:17 jbl-4312 volumio[8050]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 14:15:17 jbl-4312 sudo[8523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Dec 30 14:15:17 jbl-4312 sudo[8523]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 30 14:15:17 jbl-4312 volumio[8050]: info: FusionDsp - Reporting Fusion DSP Enabled Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Adding Signal Path Element [object Object] Dec 30 14:15:17 jbl-4312 volumio[8050]: info: Adding fusiondspeq DSP Signal Path Element Dec 30 14:15:17 jbl-4312 volumio[8050]: info: FusionDsp - ---- installed callbackRead Dec 30 14:15:17 jbl-4312 volumio[8050]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 14:15:18 jbl-4312 sudo[8523]: pam_unix(sudo:session): session closed for user root Dec 30 14:15:18 jbl-4312 volumio[8050]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Dec 30 14:15:18 jbl-4312 volumio[8050]: at Process.ChildProcess._handle.onexit (internal/child_process.js:277:19) Dec 30 14:15:18 jbl-4312 volumio[8050]: at onErrorNT (internal/child_process.js:472:16) Dec 30 14:15:18 jbl-4312 volumio[8050]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Dec 30 14:15:18 jbl-4312 volumio[8050]: at runNextTicks (internal/process/task_queues.js:64:3) Dec 30 14:15:18 jbl-4312 volumio[8050]: at listOnTimeout (internal/timers.js:526:9) Dec 30 14:15:18 jbl-4312 volumio[8050]: at processTimers (internal/timers.js:500:7) { Dec 30 14:15:18 jbl-4312 volumio[8050]: errno: -2, Dec 30 14:15:18 jbl-4312 volumio[8050]: code: 'ENOENT', Dec 30 14:15:18 jbl-4312 volumio[8050]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Dec 30 14:15:18 jbl-4312 volumio[8050]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Dec 30 14:15:18 jbl-4312 volumio[8050]: spawnargs: [ Dec 30 14:15:18 jbl-4312 volumio[8050]: '-p', Dec 30 14:15:18 jbl-4312 volumio[8050]: 9876, Dec 30 14:15:18 jbl-4312 volumio[8050]: '-o', Dec 30 14:15:18 jbl-4312 volumio[8050]: '/tmp/camilladsp.log', Dec 30 14:15:18 jbl-4312 volumio[8050]: '-l', Dec 30 14:15:18 jbl-4312 volumio[8050]: 'warn', Dec 30 14:15:18 jbl-4312 volumio[8050]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Dec 30 14:15:18 jbl-4312 volumio[8050]: ] Dec 30 14:15:18 jbl-4312 volumio[8050]: } Dec 30 14:15:18 jbl-4312 volumio[8050]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 14:15:18 jbl-4312 dbus-daemon[2832]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.8" (uid=0 pid=3333 comm="/usr/bin/volumio5-onboarding " label="kernel") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=3196 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn" label="kernel") Dec 30 14:15:18 jbl-4312 sudo[8534]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-30 14:14 Dec 30 14:15:18 jbl-4312 sudo[8534]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"