-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2026-02-21 18:45:21 CET. -- Feb 21 18:44:49 minidsp systemd-timedated[898]: Changed local time to Sat Feb 21 18:44:49 2026 Feb 21 18:44:49 minidsp sudo[896]: pam_unix(sudo:session): session closed for user root Feb 21 18:44:49 minidsp volumio-time-update[475]: volumio-time-update-util: System time updated successfully. Feb 21 18:44:49 minidsp systemd[1]: Started Volumio Time Update Utility. Feb 21 18:44:49 minidsp systemd[1]: Starting Daily apt download activities... Feb 21 18:44:49 minidsp ntpd[835]: ntpd exiting on signal 15 (Terminated) Feb 21 18:44:49 minidsp systemd[1]: Stopping Network Time Service... Feb 21 18:44:49 minidsp systemd[1]: ntp.service: Succeeded. Feb 21 18:44:49 minidsp systemd[1]: Stopped Network Time Service. Feb 21 18:44:49 minidsp systemd[1]: Starting Network Time Service... Feb 21 18:44:49 minidsp ntpd[935]: ntpd 4.2.8p12@1.3728-o (1): Starting Feb 21 18:44:49 minidsp ntpd[935]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Feb 21 18:44:49 minidsp systemd[1]: Started Network Time Service. Feb 21 18:44:49 minidsp ntpd[942]: proto: precision = 1.250 usec (-20) Feb 21 18:44:49 minidsp ntpd[942]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Feb 21 18:44:49 minidsp ntpd[942]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Feb 21 18:44:49 minidsp ntpd[942]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1152 days ago Feb 21 18:44:49 minidsp ntpd[942]: Listen and drop on 0 v6wildcard [::]:123 Feb 21 18:44:49 minidsp ntpd[942]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Feb 21 18:44:49 minidsp ntpd[942]: Listen normally on 2 lo 127.0.0.1:123 Feb 21 18:44:49 minidsp ntpd[942]: Listen normally on 3 eth0 192.168.1.147:123 Feb 21 18:44:49 minidsp ntpd[942]: Listening on routing socket on fd #20 for interface updates Feb 21 18:44:49 minidsp ntpd[942]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Feb 21 18:44:49 minidsp ntpd[942]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Feb 21 18:44:49 minidsp volumio[753]: info: Loading plugin "upnp_browser"... Feb 21 18:44:50 minidsp volumio[753]: info: Loading plugin "bluetooth"... Feb 21 18:44:50 minidsp nmbd[714]: [2026/02/21 18:44:50.132982, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 18:44:50 minidsp systemd[1]: Started Samba NMB Daemon. Feb 21 18:44:50 minidsp nmbd[714]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 21 18:44:50 minidsp systemd[1]: Starting Samba Winbind Daemon... Feb 21 18:44:50 minidsp systemd[1]: apt-daily.service: Succeeded. Feb 21 18:44:50 minidsp systemd[1]: Started Daily apt download activities. Feb 21 18:44:50 minidsp systemd[1]: Starting Daily apt upgrade and clean activities... Feb 21 18:44:50 minidsp ntpd[942]: Soliciting pool server 80.60.67.39 Feb 21 18:44:50 minidsp volumio[753]: info: [1771695890413] Starting BluetoothController Feb 21 18:44:50 minidsp winbindd[989]: [2026/02/21 18:44:50.645949, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 21 18:44:50 minidsp volumio[753]: info: Loading plugin "alarm-clock"... Feb 21 18:44:50 minidsp winbindd[989]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 21 18:44:50 minidsp winbindd[989]: [2026/02/21 18:44:50.673298, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 18:44:50 minidsp winbindd[989]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 21 18:44:50 minidsp systemd[1]: Started Samba Winbind Daemon. Feb 21 18:44:50 minidsp systemd[1]: Starting Samba SMB Daemon... Feb 21 18:44:51 minidsp systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 21 18:44:51 minidsp systemd[1]: Started Daily apt upgrade and clean activities. Feb 21 18:44:51 minidsp volumio[753]: info: Loading plugin "manifestui"... Feb 21 18:44:51 minidsp ntpd[942]: Soliciting pool server 103.149.168.181 Feb 21 18:44:51 minidsp ntpd[942]: Soliciting pool server 178.239.19.62 Feb 21 18:44:51 minidsp smbd[1024]: [2026/02/21 18:44:51.444120, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 21 18:44:51 minidsp systemd[1]: Started Samba SMB Daemon. Feb 21 18:44:51 minidsp smbd[1024]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 21 18:44:51 minidsp systemd[1]: Reached target Multi-User System. Feb 21 18:44:51 minidsp systemd[1]: Reached target Graphical Interface. Feb 21 18:44:51 minidsp volumio[753]: info: Loading plugin "metavolumio"... Feb 21 18:44:51 minidsp systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 21 18:44:51 minidsp systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 21 18:44:51 minidsp systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 21 18:44:51 minidsp systemd[1]: Startup finished in 7.032s (kernel) + 17.168s (userspace) = 24.201s. Feb 21 18:44:52 minidsp ntpd[942]: Soliciting pool server 185.71.60.123 Feb 21 18:44:52 minidsp ntpd[942]: Soliciting pool server 45.9.2.181 Feb 21 18:44:52 minidsp ntpd[942]: Soliciting pool server 195.35.113.80 Feb 21 18:44:53 minidsp ntpd[942]: Soliciting pool server 212.192.9.189 Feb 21 18:44:53 minidsp ntpd[942]: Soliciting pool server 178.239.19.59 Feb 21 18:44:53 minidsp ntpd[942]: Soliciting pool server 5.200.6.34 Feb 21 18:44:53 minidsp ntpd[942]: Soliciting pool server 5.101.84.95 Feb 21 18:44:53 minidsp volumio[753]: info: Loading plugin "airplay_emulation"... Feb 21 18:44:53 minidsp volumio[753]: info: Starting Shairport Sync Feb 21 18:44:53 minidsp volumio[753]: info: Loading plugin "cd_controller"... Feb 21 18:44:54 minidsp volumio[753]: info: Loading plugin "last_100"... Feb 21 18:44:54 minidsp volumio[753]: info: Loading plugin "qobuzconnect"... Feb 21 18:44:54 minidsp volumio[753]: info: Loading plugin "raat"... Feb 21 18:44:54 minidsp ntpd[942]: Soliciting pool server 178.239.19.60 Feb 21 18:44:54 minidsp ntpd[942]: Soliciting pool server 81.172.248.188 Feb 21 18:44:54 minidsp volumio[753]: info: RAAT Plugin loaded Feb 21 18:44:54 minidsp volumio[753]: info: Adding restartRAATSocket REST API Endpoint Feb 21 18:44:54 minidsp volumio[753]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Feb 21 18:44:54 minidsp volumio[753]: info: Loading plugin "streaming_services"... Feb 21 18:44:55 minidsp ntpd[942]: Soliciting pool server 144.21.38.190 Feb 21 18:44:56 minidsp volumio-remote-updater[464]: [2026-02-21 18:44:56] [connect] Successful connection Feb 21 18:44:56 minidsp ntpd[942]: Soliciting pool server 2a03:b0c0:2:f0::43a3:2001 Feb 21 18:44:56 minidsp volumio[753]: info: Starting Streaming Service Transparent Proxy Feb 21 18:44:56 minidsp volumio[753]: info: Loading plugin "tidalconnect"... Feb 21 18:44:56 minidsp volumio[753]: info: Loading plugin "webradio"... Feb 21 18:44:56 minidsp volumio[753]: info: Loading plugin "i2s_dacs"... Feb 21 18:44:56 minidsp volumio[753]: info: I2S DAC not set, start Auto-detection Feb 21 18:44:56 minidsp volumio[753]: info: Loading plugin "volumiodiscovery"... Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** For more information see Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 18:44:56 minidsp node[753]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 21 18:44:56 minidsp volumio[753]: *** WARNING *** For more information see Feb 21 18:44:56 minidsp node[753]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 18:44:56 minidsp node[753]: *** WARNING *** For more information see Feb 21 18:44:56 minidsp node[753]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 21 18:44:56 minidsp node[753]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 21 18:44:56 minidsp node[753]: *** WARNING *** For more information see Feb 21 18:44:57 minidsp volumio[753]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 21 18:44:57 minidsp volumio[753]: info: Discovery: Started advertising with name: miniDSP Feb 21 18:44:57 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 18:44:57 minidsp volumio[753]: info: Loading plugin "spop"... Feb 21 18:44:58 minidsp volumio[753]: STREAMING PROXY: Starting server on port 3245 Feb 21 18:44:58 minidsp volumio[753]: Node JS runtime: 14 Feb 21 18:44:58 minidsp ntpd[942]: receive: Unexpected origin timestamp 0xed446d9a.420cb0db does not match aorg 0000000000.00000000 from server@103.149.168.181 xmt 0xed446d9a.d3d06f30 Feb 21 18:44:59 minidsp volumio[753]: info: Plugin multiroom is not enabled Feb 21 18:44:59 minidsp volumio[753]: info: Loading plugin "outputs"... Feb 21 18:44:59 minidsp volumio[753]: info: Loading plugin "albumart"... Feb 21 18:44:59 minidsp volumio[753]: info: Loading plugin "ms_surface_dial"... Feb 21 18:45:00 minidsp volumio[753]: Forking 3 albumart workers Feb 21 18:45:00 minidsp volumio[753]: info: Applying required configuration parameters for plugin ms_surface_dial Feb 21 18:45:00 minidsp volumio[753]: info: Plugin example_plugin is not enabled Feb 21 18:45:00 minidsp volumio[753]: info: Loading plugin "hi_res_audio"... Feb 21 18:45:01 minidsp volumio[753]: Starting albumart workers Feb 21 18:45:01 minidsp volumio[753]: Starting albumart workers Feb 21 18:45:01 minidsp volumio[753]: Starting albumart workers Feb 21 18:45:03 minidsp volumio[753]: info: Applying required configuration parameters for plugin hi_res_audio Feb 21 18:45:03 minidsp volumio[753]: info: Loading plugin "inputs"... Feb 21 18:45:04 minidsp volumio[753]: info: Loading plugin "qobuz"... Feb 21 18:45:06 minidsp volumio[753]: info: Loading plugin "tidal"... Feb 21 18:45:07 minidsp systemd[1]: systemd-fsckd.service: Succeeded. Feb 21 18:45:07 minidsp volumio[753]: info: Loading plugin "oem_helper"... Feb 21 18:45:09 minidsp volumio[753]: info: Applying required configuration parameters for plugin oem_helper Feb 21 18:45:09 minidsp volumio[753]: info: Loading plugin "updater_comm"... Feb 21 18:45:09 minidsp volumio[753]: info: Plugin mpdemulation is not enabled Feb 21 18:45:09 minidsp volumio[753]: info: Loading plugin "rest_api"... Feb 21 18:45:10 minidsp volumio[753]: info: Loading plugin "websocket"... Feb 21 18:45:10 minidsp volumio[753]: info: Starting Socket.io Server version 2.3.0 Feb 21 18:45:10 minidsp volumio[753]: info: Loading i18n strings for locale en Feb 21 18:45:10 minidsp volumio[753]: Updating browse sources language Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::initPlayerControls Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 18:45:10 minidsp volumio[753]: Express server listening on port 3000 Feb 21 18:45:10 minidsp volumio[753]: [Metrics] WebUI: 26s 575.27ms Feb 21 18:45:10 minidsp volumio[753]: info: CoreStateMachine::resetVolumioState Feb 21 18:45:10 minidsp volumio[753]: info: CoreStateMachine::getcurrentVolume Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::volumioRetrievevolume Feb 21 18:45:10 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:10 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:10 minidsp sudo[1145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 18:45:10 minidsp sudo[1145]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:10 minidsp sudo[1145]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Feb 21 18:45:10 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Feb 21 18:45:10 minidsp sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 18:45:10 minidsp sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:10 minidsp volumio[753]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Feb 21 18:45:10 minidsp volumio[753]: info: Completed loading Core Plugins Feb 21 18:45:10 minidsp volumio[753]: info: Preparing to generate the ALSA configuration file Feb 21 18:45:10 minidsp sudo[1148]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:10 minidsp volumio[753]: info: Cannot read play queue from file Feb 21 18:45:10 minidsp volumio[753]: info: Volumio Network Manager: Network status updated: 1 Feb 21 18:45:10 minidsp volumio[753]: info: Asound.conf file unchanged, so no further update is needed Feb 21 18:45:10 minidsp volumio[753]: info: Output device has changed, restarting MPD Feb 21 18:45:10 minidsp sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 18:45:10 minidsp sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:10 minidsp sudo[1158]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:10 minidsp volumio[753]: info: Output device has changed, restarting Shairport Sync Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:11 minidsp sudo[1161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 18:45:11 minidsp sudo[1161]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp systemd[1]: Listening on mpd.socket. Feb 21 18:45:11 minidsp systemd[1]: Starting Music Player Daemon... Feb 21 18:45:11 minidsp volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 18:45:11 minidsp volumio[753]: info: ___________ START PLUGINS ___________ Feb 21 18:45:11 minidsp volumio[753]: info: ControllerMpd::onStart: Initializing MPD Feb 21 18:45:11 minidsp volumio[753]: info: Creating MPD Configuration file Feb 21 18:45:11 minidsp sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 21 18:45:11 minidsp sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp sudo[1168]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 18:45:11 minidsp volumio[753]: info: [1771695911154] CoreMusicLibrary::Adding element Media Servers Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:11 minidsp sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 21 18:45:11 minidsp sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 18:45:11 minidsp sudo[1166]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 18:45:11 minidsp sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp sudo[1166]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: Adding METAVOLUMIO REST API Endpoints Feb 21 18:45:11 minidsp volumio[753]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Feb 21 18:45:11 minidsp volumio[753]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Feb 21 18:45:11 minidsp volumio[753]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Feb 21 18:45:11 minidsp volumio[753]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:11 minidsp sudo[1174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP Feb 21 18:45:11 minidsp sudo[1174]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 21 18:45:11 minidsp systemd[1]: mpd.service: Succeeded. Feb 21 18:45:11 minidsp systemd[1]: Stopped Music Player Daemon. Feb 21 18:45:11 minidsp systemd[1]: Starting Music Player Daemon... Feb 21 18:45:11 minidsp kernel: Bluetooth: Core ver 2.22 Feb 21 18:45:11 minidsp kernel: NET: Registered protocol family 31 Feb 21 18:45:11 minidsp kernel: Bluetooth: HCI device and connection manager initialized Feb 21 18:45:11 minidsp kernel: Bluetooth: HCI socket layer initialized Feb 21 18:45:11 minidsp kernel: Bluetooth: L2CAP socket layer initialized Feb 21 18:45:11 minidsp kernel: Bluetooth: SCO socket layer initialized Feb 21 18:45:11 minidsp sudo[1174]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 21 18:45:11 minidsp volumio[753]: info: Preparing CD Folders Feb 21 18:45:11 minidsp volumio[753]: info: Adding CD REST API Endpoints Feb 21 18:45:11 minidsp volumio[753]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Feb 21 18:45:11 minidsp volumio[753]: info: Starting UDEV Watcher for CD Feb 21 18:45:11 minidsp volumio[753]: info: Detecting CD presence with UDEV Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Feb 21 18:45:11 minidsp sudo[1177]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 21 18:45:11 minidsp sudo[1177]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp sudo[1177]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 21 18:45:11 minidsp sudo[1177]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 18:45:11 minidsp volumio[753]: info: [1771695911405] CoreMusicLibrary::Adding element Last_100 Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:11 minidsp volumio[753]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: QobuzConnect: Starting Qobuz Connect socket and service Feb 21 18:45:11 minidsp volumio[753]: info: Starting RAAT Plugin Feb 21 18:45:11 minidsp sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Feb 21 18:45:11 minidsp sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Feb 21 18:45:11 minidsp volumio[753]: info: Additional UI Settings Added for plugin music_service/raat Feb 21 18:45:11 minidsp volumio[753]: info: Streaming services startup Feb 21 18:45:11 minidsp volumio[753]: info: Starting Streaming Daemon Feb 21 18:45:11 minidsp sudo[1192]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Feb 21 18:45:11 minidsp sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp sudo[1198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 21 18:45:11 minidsp sudo[1198]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp volumio-remote-updater[464]: [2026-02-21 18:45:11] [connect] Successful connection Feb 21 18:45:11 minidsp systemd[1]: Started Volumio Qobuz Connect Service. Feb 21 18:45:11 minidsp sudo[1196]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp sudo[1198]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 18:45:11 minidsp volumio[753]: info: [1771695911733] CoreMusicLibrary::Adding element Webradio Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:11 minidsp sudo[1210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Feb 21 18:45:11 minidsp sudo[1210]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 18:45:11 minidsp volumio[753]: info: Initializing BBC Radios Feb 21 18:45:11 minidsp sudo[1210]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:11 minidsp volumio[753]: info: Creating Spotify config file Feb 21 18:45:11 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:11 minidsp dbus-daemon[467]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.10' (uid=1000 pid=753 comm="/usr/bin/node /volumio/index.js ") Feb 21 18:45:11 minidsp volumio[753]: error: Hi Res Audio Failed Login: Missing Login Data Feb 21 18:45:11 minidsp systemd[1]: Starting Bluetooth service... Feb 21 18:45:11 minidsp volumio[753]: info: Adding HIGHRESAUDIO REST API Endpoints Feb 21 18:45:11 minidsp volumio[753]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Feb 21 18:45:11 minidsp volumio[753]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:12 minidsp bluetoothd[1224]: Bluetooth daemon 5.23 Feb 21 18:45:12 minidsp volumio[753]: info: Volumio Calling Home Feb 21 18:45:12 minidsp dbus-daemon[467]: [system] Successfully activated service 'org.bluez' Feb 21 18:45:12 minidsp systemd[1]: Started Bluetooth service. Feb 21 18:45:12 minidsp bluetoothd[1224]: Starting SDP server Feb 21 18:45:12 minidsp kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Feb 21 18:45:12 minidsp kernel: Bluetooth: BNEP filters: protocol multicast Feb 21 18:45:12 minidsp kernel: Bluetooth: BNEP socket layer initialized Feb 21 18:45:12 minidsp bluetoothd[1224]: Bluetooth management interface 1.14 initialized Feb 21 18:45:12 minidsp dbus-daemon[467]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.12' (uid=0 pid=1224 comm="/usr/local/libexec/bluetooth/bluetoothd ") Feb 21 18:45:12 minidsp systemd[1]: Starting Hostname Service... Feb 21 18:45:12 minidsp volumio[753]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Feb 21 18:45:12 minidsp volumio[753]: info: Stopping AccessToken refresher cron for QOBUZ Feb 21 18:45:12 minidsp volumio[753]: info: AccessToken refresher cron started for QOBUZ Feb 21 18:45:12 minidsp volumio[753]: info: Adding TIDAL REST API Endpoints Feb 21 18:45:12 minidsp volumio[753]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Feb 21 18:45:12 minidsp volumio[753]: info: Adding QOBUZ REST API Endpoints Feb 21 18:45:12 minidsp volumio[753]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Feb 21 18:45:12 minidsp dbus-daemon[467]: [system] Successfully activated service 'org.freedesktop.hostname1' Feb 21 18:45:12 minidsp systemd[1]: Started Hostname Service. Feb 21 18:45:12 minidsp volumio[753]: info: Setting Device type: NanoPi NEO 2 Feb 21 18:45:12 minidsp volumio[753]: info: CoreStateMachine::setRepeat null single undefined Feb 21 18:45:12 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: CoreStateMachine::setRandom null Feb 21 18:45:12 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: Serial port opened successfully Feb 21 18:45:12 minidsp volumio[753]: error: Cannot start Volumio Streaming Daemon Feb 21 18:45:12 minidsp volumio[753]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 21 18:45:12 minidsp volumio[753]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 21 18:45:12 minidsp volumio[753]: info: RAAT Albumart path created successfully Feb 21 18:45:12 minidsp volumio[753]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP' Feb 21 18:45:12 minidsp volumio[753]: Can't get device info: No such device Feb 21 18:45:12 minidsp volumio[753]: info: MPD Permissions set Feb 21 18:45:12 minidsp volumio[753]: info: MPD Permissions set Feb 21 18:45:12 minidsp volumio[753]: info: msSurfaceDial volumioupdatevolume callback: {"vol":88,"dbVolume":-15,"disableVolumeControl":false} Feb 21 18:45:12 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:12 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Feb 21 18:45:12 minidsp volumio[753]: info: Ignoring ROON Volume update because of undefined data Feb 21 18:45:12 minidsp volumio[753]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Feb 21 18:45:12 minidsp volumio[753]: info: [msSurfaceDial init()] check /org/bluez Feb 21 18:45:12 minidsp volumio[753]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Feb 21 18:45:12 minidsp sudo[1241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 18:45:12 minidsp sudo[1241]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:12 minidsp volumio[753]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::Reload Ui Feb 21 18:45:12 minidsp volumio-remote-updater[464]: [2026-02-21 18:45:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1771695911 101 Feb 21 18:45:12 minidsp systemd[1]: Started UPnP Renderer front-end to MPD. Feb 21 18:45:12 minidsp volumio[753]: 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: 1 Feb 21 18:45:12 minidsp sudo[1241]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:12 minidsp volumio[753]: info: Executing endpoint qc_getconfig Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Feb 21 18:45:12 minidsp qobuz-connect[1204]: 20260221 18:45:12.944 [1204.1204] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Feb 21 18:45:12 minidsp volumio[753]: info: Volumio called home Feb 21 18:45:12 minidsp volumio[753]: info: Spotify config file written Feb 21 18:45:12 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Feb 21 18:45:12 minidsp volumio[753]: info: updateDSP function in raat called! Feb 21 18:45:13 minidsp volumio[753]: info: Updating RAAT Signal Path Feb 21 18:45:13 minidsp volumio[753]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Feb 21 18:45:13 minidsp volumio[753]: info: Reconfiguring and Restarting RAAT Plugin Feb 21 18:45:13 minidsp sudo[1247]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 18:45:13 minidsp sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:13 minidsp systemd[1]: Started go-librespot Daemon. Feb 21 18:45:13 minidsp sudo[1247]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:13 minidsp go-librespot[1250]: go-librespot daemon starting... Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: Not Reporting Auto name since its the default one Feb 21 18:45:13 minidsp volumio[753]: info: RAAT Overriding default device vendor model Feb 21 18:45:13 minidsp volumio[753]: info: Adding MINIDSP Inputs Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 18:45:13 minidsp volumio[753]: info: [1771695913113] CoreMusicLibrary::Adding element Inputs Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 21 18:45:13 minidsp volumio[753]: info: [1771695913119] CoreMusicLibrary::Adding element Presets Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:13 minidsp volumio[753]: Cannot find translation for source Presets Feb 21 18:45:13 minidsp volumio[753]: (node:753) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Feb 21 18:45:13 minidsp volumio[753]: (Use `node --trace-deprecation ...` to show where the warning was created) Feb 21 18:45:13 minidsp volumio[753]: info: Discovery: adding 55c3daea-1a98-4f36-8790-fa51fa31b572 Feb 21 18:45:13 minidsp volumio[753]: info: Discovery: Found device miniDSP Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:13 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:13 minidsp volumio[753]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.215 [1204.1204] INFO VolumeManager: [0x8139e0]: Setting new playback volume: 75 Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.215 [1204.1204] INFO VolumeManager: [0x8139e0]: Setting new mute state: 0 Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.215 [1204.1204] INFO QobuzConnect: [0x8143b0]: Client initialized! Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.215 [1204.1204] INFO SampleApp: Starting Avahi advertising, name: miniDSP, service name: _qobuz-connect._tcp Feb 21 18:45:13 minidsp volumio[753]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Feb 21 18:45:13 minidsp volumio[753]: info: QobuzConnect: QOBUZ Connect daemon connected Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.230 [1204.1204] INFO LocalConfigManager: [0x8132c0]: Starting Local Configuration server Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.231 [1204.1204] INFO SampleApp: Starting Local configuration server Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.231 [1204.1204] INFO SampleApp: Playback volume changed: 75 Feb 21 18:45:13 minidsp qobuz-connect[1204]: 20260221 18:45:13.232 [1204.1204] INFO SampleApp: Connected to UNIX socket client 0x808ed8 Feb 21 18:45:13 minidsp volumio[753]: info: Upmpdcli Daemon Started Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:13 minidsp volumio[753]: info: No need to fix Spotify hosts Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:13 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:13 minidsp volumio[753]: info: Starting Shairport Sync Feb 21 18:45:13 minidsp volumio[753]: info: Starting Shairport Sync Feb 21 18:45:13 minidsp sudo[1275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 18:45:13 minidsp sudo[1275]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:13 minidsp volumio[753]: info: Starting Shairport Sync Feb 21 18:45:13 minidsp sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 18:45:13 minidsp sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Feb 21 18:45:13 minidsp systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 18:45:13 minidsp systemd[1]: shairport-sync.service: Succeeded. Feb 21 18:45:13 minidsp systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 18:45:13 minidsp sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 21 18:45:13 minidsp sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:13 minidsp systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 18:45:13 minidsp sudo[1275]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:13 minidsp sudo[1278]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:13 minidsp systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 21 18:45:13 minidsp go-librespot[1250]: time="2026-02-21T18:45:13+01:00" level=info msg="running go-librespot 0.6.2" Feb 21 18:45:13 minidsp systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 21 18:45:13 minidsp systemd[1]: shairport-sync.service: Succeeded. Feb 21 18:45:13 minidsp systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 21 18:45:13 minidsp go-librespot[1250]: time="2026-02-21T18:45:13+01:00" level=debug msg="app state loaded" Feb 21 18:45:13 minidsp go-librespot[1250]: time="2026-02-21T18:45:13+01:00" level=debug msg="stored credentials not found" Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::volumiosetSourceActiveno-source Feb 21 18:45:13 minidsp go-librespot[1250]: time="2026-02-21T18:45:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 18:45:13 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 21 18:45:13 minidsp systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 21 18:45:13 minidsp volumio[753]: Cannot find translation for source Presets Feb 21 18:45:13 minidsp sudo[1281]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:13 minidsp sudo[1288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Feb 21 18:45:13 minidsp sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:14 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:14 minidsp systemd[1]: Started RAAT DAEMON. Feb 21 18:45:14 minidsp sudo[1288]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:14 minidsp volumio[753]: info: Shairport-Sync Started Feb 21 18:45:14 minidsp volumio[753]: Error adding Membership: Error: addMembership EINVAL Feb 21 18:45:14 minidsp volumio[753]: info: Shairport-Sync Started Feb 21 18:45:14 minidsp volumio[753]: info: Shairport-Sync Started Feb 21 18:45:14 minidsp volumio[753]: info: Raat Daemon started successfully Feb 21 18:45:14 minidsp sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Feb 21 18:45:14 minidsp sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:14 minidsp systemd[1]: Started Volumio Bluetooth Module. Feb 21 18:45:14 minidsp sudo[1304]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:14 minidsp volumio[753]: info: Executing endpoint restartRAATSocket Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Feb 21 18:45:14 minidsp go-librespot[1250]: time="2026-02-21T18:45:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 18:45:14 minidsp go-librespot[1250]: time="2026-02-21T18:45:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 18:45:14 minidsp go-librespot[1250]: time="2026-02-21T18:45:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 18:45:14 minidsp go-librespot[1250]: time="2026-02-21T18:45:14+01:00" level=info msg="zeroconf server listening on port 33399" Feb 21 18:45:14 minidsp sudo[1308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Feb 21 18:45:14 minidsp sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:14 minidsp volumiobt[1306]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Feb 21 18:45:14 minidsp sudo[1308]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:14 minidsp volumio[753]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 21 18:45:14 minidsp volumio[753]: info: Volumio BT Module successfully started Feb 21 18:45:14 minidsp volumio[753]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:14 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:14 minidsp volumio[753]: info: TidalConnect service stoped! Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 21 18:45:14 minidsp volumio[753]: info: Enabling external Volume Control Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:14 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 18:45:14 minidsp volumio[753]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Feb 21 18:45:14 minidsp volumio[753]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Feb 21 18:45:15 minidsp sudo[1320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Feb 21 18:45:15 minidsp sudo[1320]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:15 minidsp systemd[1]: Started Volumio Tidal Connect Service. Feb 21 18:45:15 minidsp sudo[1320]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:15 minidsp sudo[1325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Feb 21 18:45:15 minidsp sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:15 minidsp volumiobt[1306]: pulseaudio: no process found Feb 21 18:45:15 minidsp sudo[1325]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:15 minidsp volumio[753]: info: Executing endpoint tc_getconfig Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Feb 21 18:45:15 minidsp vtcs[1322]: STARTING TidalConnect services, version: 1.5.1-beta1 Feb 21 18:45:15 minidsp vtcs[1322]: STARTED TidalConnect services. Feb 21 18:45:15 minidsp dbus-daemon[467]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.18' (uid=1000 pid=1333 comm="/usr/bin/pulseaudio --high-priority=true ") Feb 21 18:45:15 minidsp volumio[753]: info: Executing endpoint tc_connect Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Feb 21 18:45:15 minidsp volumio[753]: info: Connecting to TidalConnect Feb 21 18:45:15 minidsp systemd[1]: Starting RealtimeKit Scheduling Policy Service... Feb 21 18:45:15 minidsp volumio[753]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 18:45:15 minidsp dbus-daemon[467]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Feb 21 18:45:15 minidsp systemd[1]: Started RealtimeKit Scheduling Policy Service. Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Successfully called chroot. Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Successfully dropped privileges. Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Successfully limited resources. Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Running. Feb 21 18:45:15 minidsp dbus-daemon[467]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.19' (uid=0 pid=1338 comm="/usr/lib/rtkit/rtkit-daemon ") Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Canary thread running. Feb 21 18:45:15 minidsp rtkit-daemon[1338]: Watchdog thread running. Feb 21 18:45:15 minidsp systemd[1]: Starting Authorization Manager... Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::servicePushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Feb 21 18:45:15 minidsp volumio[753]: verbose: CURRENT POSITION 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::syncState stateService stop Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::syncState currentStatus stop Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: No code Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::servicePushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Feb 21 18:45:15 minidsp volumio[753]: verbose: CURRENT POSITION 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::syncState stateService stop Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::syncState currentStatus stop Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: No code Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 18:45:15 minidsp polkitd[1343]: started daemon version 0.105 using authority implementation `local' version `0.105' Feb 21 18:45:15 minidsp dbus-daemon[467]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Feb 21 18:45:15 minidsp systemd[1]: Started Authorization Manager. Feb 21 18:45:15 minidsp mpd[1188]: Feb 21 18:45 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 21 18:45:15 minidsp volumio[753]: info: msSurfaceDial volumioupdatevolume callback: {"vol":88,"dbVolume":-15,"mute":false,"disableVolumeControl":false} Feb 21 18:45:15 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:15 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:15 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:16 minidsp systemd[1]: Started Music Player Daemon. Feb 21 18:45:16 minidsp volumio[753]: Upnp client error: Error: This socket has been ended by the other party Feb 21 18:45:16 minidsp sudo[1161]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:16 minidsp sudo[1171]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:16 minidsp volumio[753]: error: MPD error: The expression evaluated to a falsy value: Feb 21 18:45:16 minidsp volumio[753]: assert.ok(self.idling) Feb 21 18:45:16 minidsp volumio[753]: error: The expression evaluated to a falsy value: Feb 21 18:45:16 minidsp volumio[753]: assert.ok(self.idling) Feb 21 18:45:16 minidsp volumio[753]: info: MPD running with PID1188 Feb 21 18:45:16 minidsp volumio[753]: ,establishing connection Feb 21 18:45:16 minidsp volumio[753]: error: updateQueue error: null Feb 21 18:45:16 minidsp volumio[753]: error: updateQueue error: null Feb 21 18:45:16 minidsp pulseaudio[1333]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Feb 21 18:45:16 minidsp pulseaudio[1333]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Feb 21 18:45:16 minidsp volumiobt[1306]: Applying permissions Feb 21 18:45:16 minidsp volumiobt[1306]: Setting BT discoverable and pairable Feb 21 18:45:16 minidsp pulseaudio[1333]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Feb 21 18:45:16 minidsp volumiobt[1306]: [38B blob data] Feb 21 18:45:16 minidsp volumiobt[1306]: Invalid command Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# agent on Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# discoverable on Feb 21 18:45:16 minidsp volumiobt[1306]: No default controller available Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# pairable on Feb 21 18:45:16 minidsp volumiobt[1306]: No default controller available Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# agent NoInputNoOutput Feb 21 18:45:16 minidsp volumiobt[1306]: Failed to register agent object Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# default-agent Feb 21 18:45:16 minidsp volumiobt[1306]: No agent is registered Feb 21 18:45:16 minidsp volumiobt[1306]: [bluetooth]# quit Feb 21 18:45:16 minidsp volumiobt[1306]: [61B blob data] Feb 21 18:45:16 minidsp volumiobt[1306]: [62B blob data] Feb 21 18:45:16 minidsp volumio[753]: info: go-librespot daemon successfully initialized Feb 21 18:45:16 minidsp volumio[753]: info: msSurfaceDial volumioupdatevolume callback: {"vol":88,"dbVolume":-15,"mute":false,"disableVolumeControl":false} Feb 21 18:45:16 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:16 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:16 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:16 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:16 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:16 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Feb 21 18:45:16 minidsp volumio[1243]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 21 18:45:18 minidsp volumio[753]: info: TidalConnect service started! Feb 21 18:45:18 minidsp volumio[753]: info: Completed starting Core Plugins Feb 21 18:45:18 minidsp volumio[753]: info: ------------------------------------------- Feb 21 18:45:18 minidsp volumio[753]: info: ----- MyVolumio plugins startup ---- Feb 21 18:45:18 minidsp volumio[753]: info: ------------------------------------------- Feb 21 18:45:18 minidsp volumio[753]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 21 18:45:19 minidsp sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 21 18:45:19 minidsp sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="obtained new client token: AAAna7WhZ8A+/Lp6VggELrraUGfhUK4P6YUu+6OBubDPGukQjy2fcL7YsL7UDdp8FjdTEiQkq54ph7bmfc8Kb4vPTut+yVcRc4y7Mj3fyr+xtD4g8KGS+tYXsk+BUcrtw+DG7tzdG2QhCl1VMRe0KCm4hR0Evc310tyT4e5bwK55fDpNUS6zXhycS+Rf4mvU00wE0HObvqKJwX+aRTlbI6kI7SMzZVRBS/KgKmIxQJ2vn/dm9QD4HIg=" Feb 21 18:45:19 minidsp sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 21 18:45:19 minidsp sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 21 18:45:19 minidsp systemd[1]: Started MPD Monitor Service. Feb 21 18:45:19 minidsp sudo[1390]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:19 minidsp mpd_monitor.sh[1396]: MPD Monitor Service: Starting MPD Monitor Service Feb 21 18:45:19 minidsp volumio[753]: info: Successfully started MPD Monitor Feb 21 18:45:19 minidsp systemd[1]: Stopping MPD Monitor Service... Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="completed keyexchange" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="completed challenge" Feb 21 18:45:19 minidsp systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Feb 21 18:45:19 minidsp systemd[1]: mpd_monitor.service: Succeeded. Feb 21 18:45:19 minidsp systemd[1]: Stopped MPD Monitor Service. Feb 21 18:45:19 minidsp systemd[1]: Started MPD Monitor Service. Feb 21 18:45:19 minidsp volumio[753]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 18:45:19 minidsp sudo[1393]: pam_unix(sudo:session): session closed for user root Feb 21 18:45:19 minidsp volumio[753]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 21 18:45:19 minidsp mpd_monitor.sh[1399]: MPD Monitor Service: Starting MPD Monitor Service Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=info msg="authenticated AP" username="ja******r1" Feb 21 18:45:19 minidsp volumio[753]: info: Successfully started MPD Monitor Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=info msg="authenticated Login5" username="ja******r1" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=info msg="accepted zeroconf from iPhone" username="ja******r1" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="dealer connection opened" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=trace msg="starting accesspoint recv loop" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=trace msg="starting dealer recv loop" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=trace msg="received accesspoint ping" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="received connection id: NzIyMGJjZmItMWRj...MUZBMDNFQjJGRA==" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=trace msg="received accesspoint pong ack" Feb 21 18:45:19 minidsp volumio[753]: info: Initializing connection to go-librespot Websocket Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="new websocket client" Feb 21 18:45:19 minidsp volumio[753]: info: Connection to go-librespot Websocket established Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="update volume requested to 52428/65535" Feb 21 18:45:19 minidsp systemd[1]: systemd-timedated.service: Succeeded. Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 21 18:45:19 minidsp go-librespot[1250]: time="2026-02-21T18:45:19+01:00" level=trace msg="emitting websocket event: volume" Feb 21 18:45:19 minidsp volumio[753]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Feb 21 18:45:19 minidsp volumio[753]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Feb 21 18:45:19 minidsp volumio[753]: info: Setting Volumio Volume from Spotify: 80 Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume Feb 21 18:45:19 minidsp volumio[753]: info: msSurfaceDial volumioupdatevolume callback: {"vol":80,"dbVolume":-25.5,"mute":false,"disableVolumeControl":false} Feb 21 18:45:19 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:19 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:19 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:19 minidsp volumio[753]: info: msSurfaceDial volumioupdatevolume callback: {"vol":80,"dbVolume":-25.5,"mute":false,"disableVolumeControl":false} Feb 21 18:45:19 minidsp volumio[753]: info: CoreStateMachine::pushState Feb 21 18:45:19 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::volumioPushState Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:19 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:19 minidsp volumio[753]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="handling transfer player command from 0247fc37b2b99c7d040f4f3cf3f2723bde4cf871" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E8NRb3qzOSGI7" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E8NRb3qzOSGI7" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="emitting websocket event: will_play" Feb 21 18:45:20 minidsp volumio[753]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E8NRb3qzOSGI7","uri":"spotify:track:1wv7Ag3trG3NB949l7fQFW","play_origin":"playlist/ondemand"}} Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="selected format OGG_VORBIS_320 (f3daa3c313dabbc8c80226736cd4aa85906da641)" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="requested aes key for file f3daa3c313dabbc8c80226736cd4aa85906da641, gid: 1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1340" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1114" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="fetched first chunk of 12, total size is 6008030 bytes" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="created new output device" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 166666 us, period size = 7350 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 3 frames, PCM format = FLOAT_LE" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=info msg="loaded track \"Paradise\" (paused: false, position: 1ms, duration: 143589ms, prefetched: false)" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="scheduling prefetch in 114s" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="emitting websocket event: metadata" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="emitting websocket event: active" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="sending successful reply for dealer request" Feb 21 18:45:20 minidsp volumio[753]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1wv7Ag3trG3NB949l7fQFW","name":"Paradise","artist_names":["INGO","Aexcit","Rufus Palma","Sarah Bird"],"album_name":"Paradise","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024da48d10e5ce6363982e6aca","position":1,"duration":143589,"release_date":"year:2025 month:1 day:17","track_number":1,"disc_number":1}} Feb 21 18:45:20 minidsp volumio[753]: SPOTIFY: received: {"type":"active","data":null} Feb 21 18:45:20 minidsp volumio[753]: info: Aligning Spotify Volume to Volumio Volume Feb 21 18:45:20 minidsp volumio[753]: info: CoreCommandRouter::volumioGetState Feb 21 18:45:20 minidsp volumio[753]: info: CorePlayQueue::getTrack 0 Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 18:45:20 minidsp volumio[753]: info: Setting Spotify Volume from Volumio: 80 Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=trace msg="emitting websocket event: playing" Feb 21 18:45:20 minidsp volumio[753]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E8NRb3qzOSGI7","uri":"spotify:track:1wv7Ag3trG3NB949l7fQFW","resume":false,"play_origin":"playlist/ondemand"}} Feb 21 18:45:20 minidsp volumio[753]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 18:45:20 minidsp go-librespot[1250]: time="2026-02-21T18:45:20+01:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:20 minidsp volumio[753]: TypeError: Cannot read property 'service' of undefined Feb 21 18:45:20 minidsp volumio[753]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 21 18:45:20 minidsp volumio[753]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Feb 21 18:45:20 minidsp volumio[753]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 21 18:45:20 minidsp volumio[753]: at WebSocket.emit (events.js:400:28) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.emit (events.js:400:28) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 21 18:45:20 minidsp volumio[753]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 21 18:45:20 minidsp volumio[753]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 21 18:45:20 minidsp volumio[753]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 21 18:45:20 minidsp volumio[753]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 21 18:45:20 minidsp volumio[753]: at Socket.emit (events.js:400:28) Feb 21 18:45:20 minidsp volumio[753]: at addChunk (internal/streams/readable.js:293:12) Feb 21 18:45:20 minidsp volumio[753]: at readableAddChunk (internal/streams/readable.js:267:9) Feb 21 18:45:20 minidsp volumio[753]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 18:45:21 minidsp go-librespot[1250]: time="2026-02-21T18:45:21+01:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:21 minidsp go-librespot[1250]: time="2026-02-21T18:45:21+01:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:1wv7Ag3trG3NB949l7fQFW" Feb 21 18:45:21 minidsp sudo[1416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-21 18:44 Feb 21 18:45:21 minidsp sudo[1416]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 18 Nov 2025 04:14:14 PM CET" VOLUMIO_VERSION="3.877" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="57978c68a391dbf6badbe915e5672a72"