-- Logs begin at Thu 2019-02-14 02:11:59 PST, end at Sat 2026-03-28 19:04:14 PDT. -- Nov 22 06:37:35 minidsp-shd ntpd[853]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Nov 22 06:37:35 minidsp-shd ntpd[853]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1061 days ago Mar 28 19:03:27 minidsp-shd volumio-time-update[520]: volumio-time-update-util: System time updated successfully. Mar 28 19:03:27 minidsp-shd systemd-timedated[840]: Changed local time to Sat Mar 28 19:03:27 2026 Nov 22 06:37:35 minidsp-shd ntpd[853]: Listen and drop on 0 v6wildcard [::]:123 Mar 28 19:03:27 minidsp-shd systemd[1]: Started Volumio Time Update Utility. Mar 28 19:03:27 minidsp-shd ntpd[853]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Mar 28 19:03:27 minidsp-shd ntpd[853]: Listen normally on 2 lo 127.0.0.1:123 Mar 28 19:03:27 minidsp-shd ntpd[853]: Listen normally on 3 eth0 192.168.1.179:123 Mar 28 19:03:27 minidsp-shd ntpd[853]: Listening on routing socket on fd #20 for interface updates Mar 28 19:03:27 minidsp-shd ntpd[853]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Mar 28 19:03:27 minidsp-shd ntpd[853]: kernel reports TIME_ERROR: 0x4041: Clock Unsynchronized Mar 28 19:03:27 minidsp-shd sudo[811]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:27 minidsp-shd systemd[1]: Starting Daily apt download activities... Mar 28 19:03:27 minidsp-shd nmbd[665]: [2026/03/28 19:03:27.236609, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 28 19:03:27 minidsp-shd nmbd[665]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Mar 28 19:03:27 minidsp-shd systemd[1]: Started Samba NMB Daemon. Mar 28 19:03:27 minidsp-shd systemd[1]: Starting Samba Winbind Daemon... Mar 28 19:03:27 minidsp-shd volumio[708]: info: MYVOLUMIO Environment detected Mar 28 19:03:27 minidsp-shd volumio[708]: info: Plugin folders cleanup Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning into folder /volumio/app/plugins/ Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category audio_interface Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category miscellanea Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category music_service Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category plugins.json Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category system_controller Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category user_interface Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning into folder /data/plugins/ Mar 28 19:03:27 minidsp-shd volumio[708]: info: Scanning category music_service Mar 28 19:03:27 minidsp-shd volumio[708]: info: Plugin folders cleanup completed Mar 28 19:03:27 minidsp-shd volumio[708]: info: ------------------------------------------- Mar 28 19:03:27 minidsp-shd volumio[708]: info: ----- Core plugins startup ---- Mar 28 19:03:27 minidsp-shd volumio[708]: info: ------------------------------------------- Mar 28 19:03:27 minidsp-shd volumio[708]: info: Loading plugins from folder /volumio/app/plugins/ Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin upnp to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin ms_surface_dial to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin raat to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 28 19:03:27 minidsp-shd volumio[708]: info: Loading plugins from folder /data/plugins/ Mar 28 19:03:27 minidsp-shd volumio[708]: info: Loading plugin "system"... Mar 28 19:03:27 minidsp-shd winbindd[861]: [2026/03/28 19:03:27.921363, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Mar 28 19:03:27 minidsp-shd winbindd[861]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Mar 28 19:03:27 minidsp-shd winbindd[861]: [2026/03/28 19:03:27.952767, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 28 19:03:27 minidsp-shd systemd[1]: Started Samba Winbind Daemon. Mar 28 19:03:27 minidsp-shd winbindd[861]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Mar 28 19:03:27 minidsp-shd systemd[1]: Starting Samba SMB Daemon... Mar 28 19:03:28 minidsp-shd ntpd[853]: Soliciting pool server 208.113.130.146 Mar 28 19:03:28 minidsp-shd volumio[708]: info: Loading plugin "appearance"... Mar 28 19:03:28 minidsp-shd volumio-remote-updater[510]: [2026-03-28 19:03:28] [connect] Successful connection Mar 28 19:03:28 minidsp-shd systemd[1]: apt-daily.service: Succeeded. Mar 28 19:03:28 minidsp-shd systemd[1]: Started Daily apt download activities. Mar 28 19:03:28 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... Mar 28 19:03:28 minidsp-shd ntpd[853]: Soliciting pool server 143.42.229.154 Mar 28 19:03:29 minidsp-shd ntpd[853]: Soliciting pool server 172.234.44.141 Mar 28 19:03:29 minidsp-shd smbd[890]: [2026/03/28 19:03:29.094421, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 28 19:03:29 minidsp-shd systemd[1]: Started Samba SMB Daemon. Mar 28 19:03:29 minidsp-shd systemd[1]: Reached target Multi-User System. Mar 28 19:03:29 minidsp-shd systemd[1]: Reached target Graphical Interface. Mar 28 19:03:29 minidsp-shd smbd[890]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Mar 28 19:03:29 minidsp-shd systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 28 19:03:29 minidsp-shd systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 28 19:03:29 minidsp-shd systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 28 19:03:29 minidsp-shd ntpd[853]: Soliciting pool server 158.51.99.19 Mar 28 19:03:29 minidsp-shd ntpd[853]: Soliciting pool server 172.81.59.237 Mar 28 19:03:30 minidsp-shd ntpd[853]: Soliciting pool server 155.248.196.28 Mar 28 19:03:30 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 28 19:03:30 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. Mar 28 19:03:30 minidsp-shd systemd[1]: Startup finished in 5.967s (kernel) + 19.327s (userspace) = 25.295s. Mar 28 19:03:30 minidsp-shd ntpd[853]: Soliciting pool server 23.186.168.130 Mar 28 19:03:30 minidsp-shd ntpd[853]: Soliciting pool server 172.232.15.202 Mar 28 19:03:30 minidsp-shd ntpd[853]: Soliciting pool server 50.205.57.38 Mar 28 19:03:31 minidsp-shd ntpd[853]: Soliciting pool server 193.29.63.226 Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "network"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Refreshing Cached IP Addresses Mar 28 19:03:31 minidsp-shd sudo[973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 19:03:31 minidsp-shd sudo[973]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:31 minidsp-shd sudo[975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 19:03:31 minidsp-shd sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:31 minidsp-shd sudo[973]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "services"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "alsa_controller"... Mar 28 19:03:31 minidsp-shd sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 28 19:03:31 minidsp-shd sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:31 minidsp-shd sudo[975]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:31 minidsp-shd sudo[984]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:31 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "wizard"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "networkfs"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Starting Udev Watcher for removable devices Mar 28 19:03:31 minidsp-shd sudo[1003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=admin,password=myprost8,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.76/music /mnt/NAS/DiskStation Mar 28 19:03:31 minidsp-shd sudo[1003]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:31 minidsp-shd kernel: FS-Cache: Loaded Mar 28 19:03:31 minidsp-shd volumio[708]: info: Ignoring mount for partition: BOOT Mar 28 19:03:31 minidsp-shd volumio[708]: info: Ignoring mount for partition: volumio Mar 28 19:03:31 minidsp-shd volumio[708]: info: Ignoring mount for partition: volumio_data Mar 28 19:03:31 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "volumio_command_line_client"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "upnp"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: [1774749811664] Starting Upmpd Daemon Mar 28 19:03:31 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "my_music"... Mar 28 19:03:31 minidsp-shd volumio[708]: info: Loading plugin "mpd"... Mar 28 19:03:31 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching Mar 28 19:03:31 minidsp-shd kernel: Key type cifs.spnego registered Mar 28 19:03:31 minidsp-shd kernel: Key type cifs.idmap registered Mar 28 19:03:31 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.76/music Mar 28 19:03:31 minidsp-shd kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 28 19:03:31 minidsp-shd ntpd[853]: Soliciting pool server 216.66.48.42 Mar 28 19:03:31 minidsp-shd ntpd[853]: Soliciting pool server 44.190.5.123 Mar 28 19:03:31 minidsp-shd ntpd[853]: Soliciting pool server 24.249.17.243 Mar 28 19:03:32 minidsp-shd volumio[708]: info: Loading plugin "upnp_browser"... Mar 28 19:03:32 minidsp-shd ntpd[853]: Soliciting pool server 162.252.172.49 Mar 28 19:03:32 minidsp-shd ntpd[853]: Soliciting pool server 2604:a880:400:d0::83:2002 Mar 28 19:03:33 minidsp-shd volumio[708]: info: Plugin bluetooth is not enabled Mar 28 19:03:33 minidsp-shd volumio[708]: info: Loading plugin "alarm-clock"... Mar 28 19:03:33 minidsp-shd volumio[708]: info: Loading plugin "manifestui"... Mar 28 19:03:33 minidsp-shd volumio[708]: info: Loading plugin "metavolumio"... Mar 28 19:03:33 minidsp-shd ntpd[853]: Soliciting pool server 64.79.100.197 Mar 28 19:03:37 minidsp-shd ntpd[853]: receive: Unexpected origin timestamp 0xed7306f7.fe346a87 does not match aorg 0000000000.00000000 from server@50.205.57.38 xmt 0xed7306f9.05f8fcbd Mar 28 19:03:37 minidsp-shd volumio[708]: info: Loading plugin "airplay_emulation"... Mar 28 19:03:37 minidsp-shd volumio[708]: info: Starting Shairport Sync Mar 28 19:03:37 minidsp-shd volumio[708]: info: Loading plugin "cd_controller"... Mar 28 19:03:38 minidsp-shd volumio[708]: info: Loading plugin "last_100"... Mar 28 19:03:38 minidsp-shd volumio[708]: info: Loading plugin "qobuzconnect"... Mar 28 19:03:38 minidsp-shd volumio[708]: info: Loading plugin "raat"... Mar 28 19:03:38 minidsp-shd volumio[708]: info: RAAT Plugin loaded Mar 28 19:03:38 minidsp-shd volumio[708]: info: Adding restartRAATSocket REST API Endpoint Mar 28 19:03:38 minidsp-shd volumio[708]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Mar 28 19:03:38 minidsp-shd volumio[708]: info: Loading plugin "streaming_services"... Mar 28 19:03:38 minidsp-shd kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 28 19:03:38 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -113 Mar 28 19:03:38 minidsp-shd sudo[1003]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:41 minidsp-shd volumio[708]: info: Starting Streaming Service Transparent Proxy Mar 28 19:03:41 minidsp-shd volumio[708]: info: Loading plugin "tidalconnect"... Mar 28 19:03:41 minidsp-shd volumio[708]: info: Loading plugin "webradio"... Mar 28 19:03:41 minidsp-shd volumio[708]: info: Loading plugin "i2s_dacs"... Mar 28 19:03:41 minidsp-shd volumio[708]: info: I2S DAC not set, start Auto-detection Mar 28 19:03:41 minidsp-shd volumio[708]: info: Loading plugin "volumiodiscovery"... Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** For more information see Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 28 19:03:42 minidsp-shd volumio[708]: *** WARNING *** For more information see Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** For more information see Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 28 19:03:42 minidsp-shd node[708]: *** WARNING *** For more information see Mar 28 19:03:42 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 28 19:03:42 minidsp-shd volumio[708]: info: Discovery: Started advertising with name: miniDSP SHD Mar 28 19:03:42 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 19:03:42 minidsp-shd volumio[708]: info: Loading plugin "spop"... Mar 28 19:03:43 minidsp-shd volumio[708]: STREAMING PROXY: Starting server on port 3245 Mar 28 19:03:43 minidsp-shd volumio[708]: Node JS runtime: 14 Mar 28 19:03:44 minidsp-shd volumio-remote-updater[510]: [2026-03-28 19:03:44] [connect] Successful connection Mar 28 19:03:44 minidsp-shd volumio[708]: info: Plugin multiroom is not enabled Mar 28 19:03:44 minidsp-shd volumio[708]: info: Loading plugin "outputs"... Mar 28 19:03:44 minidsp-shd volumio[708]: info: Loading plugin "albumart"... Mar 28 19:03:45 minidsp-shd volumio[708]: info: Loading plugin "ms_surface_dial"... Mar 28 19:03:45 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. Mar 28 19:03:45 minidsp-shd volumio[708]: Forking 3 albumart workers Mar 28 19:03:46 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin ms_surface_dial Mar 28 19:03:46 minidsp-shd volumio[708]: info: Plugin example_plugin is not enabled Mar 28 19:03:46 minidsp-shd volumio[708]: info: Loading plugin "hi_res_audio"... Mar 28 19:03:47 minidsp-shd volumio[708]: Starting albumart workers Mar 28 19:03:47 minidsp-shd volumio[708]: Starting albumart workers Mar 28 19:03:47 minidsp-shd volumio[708]: Starting albumart workers Mar 28 19:03:50 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin hi_res_audio Mar 28 19:03:50 minidsp-shd volumio[708]: info: Loading plugin "inputs"... Mar 28 19:03:51 minidsp-shd volumio[708]: info: Loading plugin "qobuz"... Mar 28 19:03:54 minidsp-shd volumio[708]: info: Loading plugin "tidal"... Mar 28 19:03:56 minidsp-shd volumio[708]: info: Loading plugin "oem_helper"... Mar 28 19:03:58 minidsp-shd systemd[1]: systemd-timedated.service: Succeeded. Mar 28 19:03:58 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin oem_helper Mar 28 19:03:58 minidsp-shd volumio[708]: info: Loading plugin "updater_comm"... Mar 28 19:03:58 minidsp-shd volumio[708]: info: Plugin mpdemulation is not enabled Mar 28 19:03:58 minidsp-shd volumio[708]: info: Loading plugin "rest_api"... Mar 28 19:03:58 minidsp-shd volumio[708]: info: Loading plugin "websocket"... Mar 28 19:03:58 minidsp-shd volumio[708]: info: Starting Socket.io Server version 2.3.0 Mar 28 19:03:58 minidsp-shd volumio[708]: info: Loading i18n strings for locale en Mar 28 19:03:58 minidsp-shd volumio[708]: Updating browse sources language Mar 28 19:03:58 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::initPlayerControls Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:03:59 minidsp-shd volumio[708]: Express server listening on port 3000 Mar 28 19:03:59 minidsp-shd volumio[708]: [Metrics] WebUI: 34s 699.31ms Mar 28 19:03:59 minidsp-shd volumio-remote-updater[510]: [2026-03-28 19:03:59] [connect] Successful connection Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreStateMachine::resetVolumioState Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreStateMachine::getcurrentVolume Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioRetrievevolume Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:03:59 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:59 minidsp-shd sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 19:03:59 minidsp-shd sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Mar 28 19:03:59 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Mar 28 19:03:59 minidsp-shd sudo[1120]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:59 minidsp-shd sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 19:03:59 minidsp-shd sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:59 minidsp-shd volumio[708]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Mar 28 19:03:59 minidsp-shd volumio[708]: info: Completed loading Core Plugins Mar 28 19:03:59 minidsp-shd volumio[708]: info: Preparing to generate the ALSA configuration file Mar 28 19:03:59 minidsp-shd sudo[1122]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:59 minidsp-shd volumio[708]: info: Volumio Network Manager: Network status updated: 1 Mar 28 19:03:59 minidsp-shd volumio[708]: info: Cannot mount NAS DiskStation at system boot, trial number 1 ,retrying in 5 seconds Mar 28 19:03:59 minidsp-shd volumio[708]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 28 19:03:59 minidsp-shd volumio[708]: wlan0 Interface doesn't support scanning. Mar 28 19:03:59 minidsp-shd volumio[708]: info: Cannot use regular scanning, forcing with ap-force Mar 28 19:03:59 minidsp-shd sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 28 19:03:59 minidsp-shd sudo[1128]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:59 minidsp-shd sudo[1128]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:59 minidsp-shd volumio[708]: command failed: No such device (-19) Mar 28 19:03:59 minidsp-shd volumio[708]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Mar 28 19:03:59 minidsp-shd volumio[708]: command failed: No such device (-19) Mar 28 19:03:59 minidsp-shd volumio[708]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Mar 28 19:04:00 minidsp-shd volumio[708]: verbose: New Socket.io Connection to 192.168.1.179:3000 from 192.168.1.30 UA: ESP32 Websocket Client Engine version: 4 Transport: websocket Total Clients: 1 Mar 28 19:04:00 minidsp-shd volumio[708]: verbose: New Socket.io Connection to 192.168.1.179:3000 from 192.168.1.30 UA: ESP32 Websocket Client Engine version: 4 Transport: websocket Total Clients: 2 Mar 28 19:04:00 minidsp-shd volumio-remote-updater[510]: [2026-03-28 19:04:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1774749839 101 Mar 28 19:04:00 minidsp-shd volumio[708]: 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: 3 Mar 28 19:04:00 minidsp-shd volumio[708]: verbose: New Socket.io Connection to 192.168.1.179:3000 from 192.168.1.30 UA: ESP32 Websocket Client Engine version: 4 Transport: websocket Total Clients: 4 Mar 28 19:04:00 minidsp-shd volumio[708]: info: Asound.conf file unchanged, so no further update is needed Mar 28 19:04:00 minidsp-shd volumio[708]: info: Output device has changed, restarting MPD Mar 28 19:04:00 minidsp-shd sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:04:00 minidsp-shd sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd volumio[708]: info: Output device has changed, restarting Shairport Sync Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:00 minidsp-shd sudo[1138]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:00 minidsp-shd sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:04:00 minidsp-shd sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd systemd[1]: Listening on mpd.socket. Mar 28 19:04:00 minidsp-shd systemd[1]: Starting Music Player Daemon... Mar 28 19:04:00 minidsp-shd volumio[708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:04:00 minidsp-shd volumio[708]: info: ___________ START PLUGINS ___________ Mar 28 19:04:00 minidsp-shd volumio[708]: info: ControllerMpd::onStart: Initializing MPD Mar 28 19:04:00 minidsp-shd volumio[708]: info: Creating MPD Configuration file Mar 28 19:04:00 minidsp-shd sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:04:00 minidsp-shd sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:00 minidsp-shd volumio[708]: info: [1774749840652] CoreMusicLibrary::Adding element Media Servers Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:00 minidsp-shd sudo[1148]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:00 minidsp-shd sudo[1150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:04:00 minidsp-shd sudo[1150]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd sudo[1146]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 19:04:00 minidsp-shd sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd sudo[1146]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:00 minidsp-shd systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 28 19:04:00 minidsp-shd systemd[1]: mpd.service: Succeeded. Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding METAVOLUMIO REST API Endpoints Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:04:00 minidsp-shd systemd[1]: Stopped Music Player Daemon. Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:00 minidsp-shd systemd[1]: Starting Music Player Daemon... Mar 28 19:04:00 minidsp-shd volumio[708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:00 minidsp-shd sudo[1153]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 19:04:00 minidsp-shd volumio[708]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:04:00 minidsp-shd sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:00 minidsp-shd volumio[708]: info: Preparing CD Folders Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding CD REST API Endpoints Mar 28 19:04:00 minidsp-shd volumio[708]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 28 19:04:00 minidsp-shd volumio[708]: info: Starting UDEV Watcher for CD Mar 28 19:04:00 minidsp-shd volumio[708]: info: Detecting CD presence with UDEV Mar 28 19:04:00 minidsp-shd sudo[1153]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 28 19:04:00 minidsp-shd sudo[1153]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:00 minidsp-shd volumio[708]: info: [1774749840994] CoreMusicLibrary::Adding element Last_100 Mar 28 19:04:00 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:01 minidsp-shd volumio[708]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:01 minidsp-shd volumio[708]: info: QobuzConnect: Starting Qobuz Connect socket and service Mar 28 19:04:01 minidsp-shd volumio[708]: info: Starting RAAT Plugin Mar 28 19:04:01 minidsp-shd sudo[1166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Mar 28 19:04:01 minidsp-shd sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Mar 28 19:04:01 minidsp-shd volumio[708]: info: Additional UI Settings Added for plugin music_service/raat Mar 28 19:04:01 minidsp-shd volumio[708]: info: Streaming services startup Mar 28 19:04:01 minidsp-shd volumio[708]: info: Starting Streaming Daemon Mar 28 19:04:01 minidsp-shd sudo[1166]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:01 minidsp-shd sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Mar 28 19:04:01 minidsp-shd sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:01 minidsp-shd sudo[1172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 19:04:01 minidsp-shd sudo[1172]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:01 minidsp-shd sudo[1172]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:01 minidsp-shd systemd[1]: Started Volumio Qobuz Connect Service. Mar 28 19:04:01 minidsp-shd sudo[1171]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:01 minidsp-shd volumio[708]: info: [1774749841387] CoreMusicLibrary::Adding element Webradio Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:04:01 minidsp-shd volumio[708]: info: Initializing BBC Radios Mar 28 19:04:01 minidsp-shd sudo[1181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 28 19:04:01 minidsp-shd sudo[1181]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:01 minidsp-shd sudo[1181]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:01 minidsp-shd volumio[708]: info: Creating Spotify config file Mar 28 19:04:01 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:01 minidsp-shd dbus-daemon[551]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.10' (uid=1000 pid=708 comm="/usr/bin/node /volumio/index.js ") Mar 28 19:04:01 minidsp-shd volumio[708]: error: Hi Res Audio Failed Login: Missing Login Data Mar 28 19:04:01 minidsp-shd volumio[708]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 28 19:04:01 minidsp-shd systemd[1]: Starting Bluetooth service... Mar 28 19:04:01 minidsp-shd volumio[708]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 28 19:04:01 minidsp-shd volumio[708]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 28 19:04:01 minidsp-shd volumio[708]: info: Refreshing TIDAL token Mar 28 19:04:02 minidsp-shd bluetoothd[1195]: Bluetooth daemon 5.23 Mar 28 19:04:02 minidsp-shd dbus-daemon[551]: [system] Successfully activated service 'org.bluez' Mar 28 19:04:02 minidsp-shd systemd[1]: Started Bluetooth service. Mar 28 19:04:02 minidsp-shd bluetoothd[1195]: Starting SDP server Mar 28 19:04:02 minidsp-shd bluetoothd[1195]: kernel lacks bnep-protocol support Mar 28 19:04:02 minidsp-shd bluetoothd[1195]: System does not support network plugin Mar 28 19:04:02 minidsp-shd dbus-daemon[551]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.12' (uid=0 pid=1195 comm="/usr/local/libexec/bluetooth/bluetoothd ") Mar 28 19:04:02 minidsp-shd bluetoothd[1195]: Bluetooth management interface 1.14 initialized Mar 28 19:04:02 minidsp-shd systemd[1]: Starting Hostname Service... Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:02 minidsp-shd volumio[708]: info: Volumio Calling Home Mar 28 19:04:02 minidsp-shd volumio[708]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Mar 28 19:04:02 minidsp-shd dbus-daemon[551]: [system] Successfully activated service 'org.freedesktop.hostname1' Mar 28 19:04:02 minidsp-shd systemd[1]: Started Hostname Service. Mar 28 19:04:02 minidsp-shd volumio[708]: info: Stopping AccessToken refresher cron for QOBUZ Mar 28 19:04:02 minidsp-shd volumio[708]: info: AccessToken refresher cron started for QOBUZ Mar 28 19:04:02 minidsp-shd volumio[708]: info: Adding QOBUZ REST API Endpoints Mar 28 19:04:02 minidsp-shd volumio[708]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Mar 28 19:04:02 minidsp-shd volumio[708]: info: Setting Device type: NanoPi NEO 3 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreStateMachine::setRepeat false single undefined Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreStateMachine::setRandom null Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:02 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:02 minidsp-shd volumio[708]: info: Serial port opened successfully Mar 28 19:04:03 minidsp-shd volumio[708]: error: Cannot start Volumio Streaming Daemon Mar 28 19:04:03 minidsp-shd volumio[708]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 19:04:03 minidsp-shd volumio[708]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 19:04:03 minidsp-shd volumio[708]: info: RAAT Albumart path created successfully Mar 28 19:04:03 minidsp-shd volumio[708]: info: MPD Permissions set Mar 28 19:04:03 minidsp-shd volumio[708]: info: MPD Permissions set Mar 28 19:04:03 minidsp-shd volumio[708]: info: msSurfaceDial volumioupdatevolume callback: {"vol":85,"dbVolume":-19,"disableVolumeControl":false} Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:03 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:03 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Mar 28 19:04:03 minidsp-shd volumio[708]: info: Ignoring ROON Volume update because of undefined data Mar 28 19:04:03 minidsp-shd volumio[708]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Mar 28 19:04:03 minidsp-shd volumio[708]: info: [msSurfaceDial init()] check /org/bluez Mar 28 19:04:03 minidsp-shd volumio[708]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Mar 28 19:04:03 minidsp-shd sudo[1226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 28 19:04:03 minidsp-shd sudo[1226]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:03 minidsp-shd volumio[708]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::Reload Ui Mar 28 19:04:03 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. Mar 28 19:04:03 minidsp-shd sudo[1226]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:03 minidsp-shd volumio[708]: info: Executing endpoint qc_getconfig Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.551 [1180.1180] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Mar 28 19:04:03 minidsp-shd volumio[708]: info: Volumio called home Mar 28 19:04:03 minidsp-shd volumio[708]: info: Spotify config file written Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Mar 28 19:04:03 minidsp-shd volumio[708]: info: updateDSP function in raat called! Mar 28 19:04:03 minidsp-shd volumio[708]: info: Updating RAAT Signal Path Mar 28 19:04:03 minidsp-shd volumio[708]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Mar 28 19:04:03 minidsp-shd volumio[708]: info: Reconfiguring and Restarting RAAT Plugin Mar 28 19:04:03 minidsp-shd sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 19:04:03 minidsp-shd sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.725 [1180.1180] INFO VolumeManager: [0x1ba9958]: Setting new playback volume: 75 Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.726 [1180.1180] INFO VolumeManager: [0x1ba9958]: Setting new mute state: 0 Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.726 [1180.1180] INFO QobuzConnect: [0x1baa328]: Client initialized! Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.726 [1180.1180] INFO SampleApp: Starting Avahi advertising, name: miniDSP SHD, service name: _qobuz-connect._tcp Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.768 [1180.1180] INFO LocalConfigManager: [0x1ba9238]: Starting Local Configuration server Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.769 [1180.1180] INFO SampleApp: Starting Local configuration server Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.770 [1180.1180] INFO SampleApp: Playback volume changed: 75 Mar 28 19:04:03 minidsp-shd qobuz-connect[1180]: 20260328 19:04:03.771 [1180.1180] INFO SampleApp: Connected to UNIX socket client 0x1b9eed8 Mar 28 19:04:03 minidsp-shd systemd[1]: Started go-librespot Daemon. Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:03 minidsp-shd sudo[1232]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:04:03 minidsp-shd go-librespot[1239]: go-librespot daemon starting... Mar 28 19:04:03 minidsp-shd volumio[708]: info: Not Reporting Auto name since its the default one Mar 28 19:04:03 minidsp-shd volumio[708]: info: RAAT Overriding default device vendor model Mar 28 19:04:03 minidsp-shd volumio[708]: info: Adding MINIDSP Inputs Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:03 minidsp-shd volumio[708]: info: [1774749843834] CoreMusicLibrary::Adding element Inputs Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:03 minidsp-shd volumio[708]: info: [1774749843846] CoreMusicLibrary::Adding element Presets Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:03 minidsp-shd volumio[708]: Cannot find translation for source Presets Mar 28 19:04:03 minidsp-shd volumio[708]: (node:708) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Mar 28 19:04:03 minidsp-shd volumio[708]: (Use `node --trace-deprecation ...` to show where the warning was created) Mar 28 19:04:03 minidsp-shd volumio[708]: info: Discovery: adding e46f0793-b14c-4dba-99fd-edf35918d7e7 Mar 28 19:04:03 minidsp-shd volumio[708]: info: Discovery: Found device miniDSP SHD Mar 28 19:04:03 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:03 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:04 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:04-07:00" level=info msg="running go-librespot 0.4.0" Mar 28 19:04:04 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:04-07:00" level=debug msg="app state loaded" Mar 28 19:04:04 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:04-07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 19:04:04 minidsp-shd volumio[708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 28 19:04:04 minidsp-shd volumio[708]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Mar 28 19:04:04 minidsp-shd volumio[708]: info: QobuzConnect: QOBUZ Connect daemon connected Mar 28 19:04:04 minidsp-shd volumio[708]: info: Upmpdcli Daemon Started Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:04 minidsp-shd volumio[708]: info: No need to fix Spotify hosts Mar 28 19:04:04 minidsp-shd volumio[708]: info: Access Token successfully retrieved Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:04 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:04 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=info msg="zeroconf server listening on port 44451" Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:05 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 28 19:04:05 minidsp-shd volumio[708]: info: Enabling external Volume Control Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="obtained new client token: AAAFKk5d44fofXpw9syNQs9fEZZCAoqFDtrKNykcCUlqqcmwA8iGktjXHmsI8bO/e9nxl8qW9LTkWdIvLgBhgDn+XTkODLJ211OdJ4qvPJpXaBkLucmkgKYEMZa7Bi175XodAJhloFS2V4d17u8w09Rw/yoEHRQe7HPLQSN1JV57DlTNSKBZV6xLJSbFhbAakuzKnaL9o172ho7VJ0zfX2cCgPH9a+Sghg+XeGyFQL0SsdnKCzWn+Os=" Mar 28 19:04:05 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:05 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:05 minidsp-shd sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=admin,password=myprost8,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.76/music /mnt/NAS/DiskStation Mar 28 19:04:05 minidsp-shd sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:05 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.76/music Mar 28 19:04:05 minidsp-shd kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 19:04:05 minidsp-shd volumio[708]: info: TidalConnect service stoped! Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="completed keyexchange" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="completed challenge" Mar 28 19:04:05 minidsp-shd volumio[708]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 28 19:04:05 minidsp-shd volumio[708]: SPOTIFY: BQABTIshTcVEpNNsON9eEK7sQtcyQip7xLXnHm7Q0rFrQ3pZjO_VzPvZmCLBAG4V5q___Ou4XNK_sII-4BzVNxKSaK-hhffs4tMmn4m6bpdNq8N5Q2CEgpISPpJ1S3gzgcO0pm_cei7EQzbBxMpFnQN3cjZZBopc-spcS5WsIqDeefF6R2iw3iNgQKG_lMASCwbGnw4GhveGcSaAvcHf9t7qnySI_argm2ab1w9khcSUTK6z5KKGSAHjA-u-j1cAc4RX23uLHUd4CAcTfTuluV2BmrDGWYuc-nikPQ Mar 28 19:04:05 minidsp-shd volumio[708]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 28 19:04:05 minidsp-shd volumio[708]: info: New Spotify access token = BQABTIshTcVEpNNsON9eEK7sQtcyQip7xLXnHm7Q0rFrQ3pZjO_VzPvZmCLBAG4V5q___Ou4XNK_sII-4BzVNxKSaK-hhffs4tMmn4m6bpdNq8N5Q2CEgpISPpJ1S3gzgcO0pm_cei7EQzbBxMpFnQN3cjZZBopc-spcS5WsIqDeefF6R2iw3iNgQKG_lMASCwbGnw4GhveGcSaAvcHf9t7qnySI_argm2ab1w9khcSUTK6z5KKGSAHjA-u-j1cAc4RX23uLHUd4CAcTfTuluV2BmrDGWYuc-nikPQ Mar 28 19:04:05 minidsp-shd volumio[708]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 19:04:05 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::volumiosetSourceActiveno-source Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:05 minidsp-shd volumio[708]: Cannot find translation for source Presets Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioStop Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreStateMachine::stop Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=info msg="authenticated AP" username="pl******ad" Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:04:05 minidsp-shd volumio[708]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"RCA","disableUiControls":true,"albumart":"/albumart"} Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:04:05 minidsp-shd volumio[708]: info: Starting Shairport Sync Mar 28 19:04:05 minidsp-shd volumio[708]: info: Starting Shairport Sync Mar 28 19:04:05 minidsp-shd sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:04:05 minidsp-shd sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:05 minidsp-shd volumio[708]: info: Starting Shairport Sync Mar 28 19:04:05 minidsp-shd sudo[1272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:04:05 minidsp-shd sudo[1272]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:05 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:04:05 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Mar 28 19:04:05 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=info msg="authenticated Login5" username="pl******ad" Mar 28 19:04:05 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="initializing zeroconf session" username="pl******ad" Mar 28 19:04:05 minidsp-shd sudo[1276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:04:05 minidsp-shd sudo[1276]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:05 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:04:05 minidsp-shd sudo[1270]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:05 minidsp-shd sudo[1272]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:05 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:04:05 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Mar 28 19:04:05 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="dealer connection opened" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=trace msg="starting accesspoint recv loop" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=trace msg="starting dealer recv loop" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=trace msg="received accesspoint ping" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=debug msg="received connection id: NzhkZWM1M2ItMmRl...Q0VBNTEwNzZFNQ==" Mar 28 19:04:05 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:04:05 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:05-07:00" level=trace msg="received accesspoint pong ack" Mar 28 19:04:05 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:04:05 minidsp-shd sudo[1276]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:05 minidsp-shd sudo[1283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Mar 28 19:04:06 minidsp-shd sudo[1283]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:06 minidsp-shd volumio[708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 28 19:04:06 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:06-07:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 19:04:06 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:06-07:00" level=debug msg="update volume requested to 55704/65535" Mar 28 19:04:06 minidsp-shd systemd[1]: Started RAAT DAEMON. Mar 28 19:04:06 minidsp-shd sudo[1283]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreCommandRouter::servicePushState Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:06 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:06 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:06-07:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 19:04:06 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:06-07:00" level=trace msg="emitting websocket event: volume" Mar 28 19:04:06 minidsp-shd volumio[708]: info: Reloading queue from file Mar 28 19:04:06 minidsp-shd volumio[708]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 28 19:04:06 minidsp-shd volumio[708]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 28 19:04:06 minidsp-shd volumio[708]: info: Raat Daemon started successfully Mar 28 19:04:06 minidsp-shd volumio[708]: info: Shairport-Sync Started Mar 28 19:04:06 minidsp-shd volumio[708]: Error adding Membership: Error: addMembership EINVAL Mar 28 19:04:06 minidsp-shd volumio[708]: info: Shairport-Sync Started Mar 28 19:04:06 minidsp-shd volumio[708]: info: Shairport-Sync Started Mar 28 19:04:07 minidsp-shd sudo[1303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 28 19:04:07 minidsp-shd sudo[1303]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:07 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. Mar 28 19:04:07 minidsp-shd sudo[1303]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:07 minidsp-shd volumio[708]: info: Successfully retrieved User Session From TIDAL Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:07 minidsp-shd volumio[708]: info: msSurfaceDial volumioupdatevolume callback: {"vol":85,"dbVolume":-19,"mute":false,"disableVolumeControl":false} Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:07 minidsp-shd volumio[708]: error: Help! Some callbacks for volumioPushState are crashing! Mar 28 19:04:07 minidsp-shd volumio[708]: error: Cannot read property 'sendVolumeMute' of undefined Mar 28 19:04:07 minidsp-shd volumio[708]: info: Executing endpoint restartRAATSocket Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Mar 28 19:04:07 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:07 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:07 minidsp-shd volumio[708]: info: msSurfaceDial volumioupdatevolume callback: {"vol":85,"dbVolume":-19,"mute":false,"disableVolumeControl":false} Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:07 minidsp-shd volumio[708]: error: Help! Some callbacks for volumioPushState are crashing! Mar 28 19:04:07 minidsp-shd volumio[708]: error: Cannot read property 'sendVolumeMute' of undefined Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Mar 28 19:04:07 minidsp-shd volumio[708]: info: Successfully retrieved User Subscription From TIDAL Mar 28 19:04:07 minidsp-shd volumio[708]: info: Adding TIDAL to Browse Sources Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:07 minidsp-shd volumio[708]: info: [1774749847697] CoreMusicLibrary::Adding element TIDAL Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:07 minidsp-shd volumio[708]: Cannot find translation for source Presets Mar 28 19:04:07 minidsp-shd volumio[708]: Cannot find translation for source TIDAL Mar 28 19:04:07 minidsp-shd volumio[708]: info: Adding TIDAL REST API Endpoints Mar 28 19:04:07 minidsp-shd volumio[708]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Mar 28 19:04:07 minidsp-shd volumio[708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 28 19:04:07 minidsp-shd volumio[708]: SPOTIFY: User informations: {"country":"US","display_name":"plbankhead","email":"paul@bankheads.net","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/plbankhead"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/plbankhead","id":"plbankhead","images":[],"product":"premium","type":"user","uri":"spotify:user:plbankhead"} Mar 28 19:04:07 minidsp-shd volumio[708]: info: Spotify Successfully logged in Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:04:07 minidsp-shd volumio[708]: info: [1774749847783] CoreMusicLibrary::Adding element Spotify Mar 28 19:04:07 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:04:07 minidsp-shd volumio[708]: Cannot find translation for source Presets Mar 28 19:04:07 minidsp-shd volumio[708]: Cannot find translation for source TIDAL Mar 28 19:04:07 minidsp-shd volumio[708]: Cannot find translation for source Spotify Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:08 minidsp-shd volumio[708]: info: Executing endpoint tc_getconfig Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 28 19:04:08 minidsp-shd vtcs[1305]: STARTING TidalConnect services, version: 1.5.1-beta1 Mar 28 19:04:08 minidsp-shd vtcs[1305]: STARTED TidalConnect services. Mar 28 19:04:08 minidsp-shd volumio[708]: info: go-librespot daemon successfully initialized Mar 28 19:04:08 minidsp-shd volumio[708]: info: Executing endpoint tc_connect Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 28 19:04:08 minidsp-shd volumio[708]: info: Connecting to TidalConnect Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::servicePushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:08 minidsp-shd volumio[708]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::servicePushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:08 minidsp-shd volumio[708]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:08 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:08 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:08 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:08 minidsp-shd mpd[1161]: Mar 28 19:04 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 19:04:08 minidsp-shd systemd[1]: Started Music Player Daemon. Mar 28 19:04:08 minidsp-shd volumio[708]: Upnp client error: Error: This socket has been ended by the other party Mar 28 19:04:08 minidsp-shd sudo[1140]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:08 minidsp-shd sudo[1150]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:09 minidsp-shd volumio[708]: error: MPD error: The expression evaluated to a falsy value: Mar 28 19:04:09 minidsp-shd volumio[708]: assert.ok(self.idling) Mar 28 19:04:09 minidsp-shd volumio[708]: error: The expression evaluated to a falsy value: Mar 28 19:04:09 minidsp-shd volumio[708]: assert.ok(self.idling) Mar 28 19:04:09 minidsp-shd volumio[708]: error: updateQueue error: null Mar 28 19:04:09 minidsp-shd volumio[708]: info: MPD running with PID1161 Mar 28 19:04:09 minidsp-shd volumio[708]: ,establishing connection Mar 28 19:04:09 minidsp-shd volumio[708]: error: updateQueue error: null Mar 28 19:04:09 minidsp-shd volumio[1228]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 28 19:04:10 minidsp-shd volumio[708]: info: TidalConnect service started! Mar 28 19:04:10 minidsp-shd volumio[708]: info: Completed starting Core Plugins Mar 28 19:04:10 minidsp-shd volumio[708]: info: ------------------------------------------- Mar 28 19:04:10 minidsp-shd volumio[708]: info: ----- MyVolumio plugins startup ---- Mar 28 19:04:10 minidsp-shd volumio[708]: info: ------------------------------------------- Mar 28 19:04:10 minidsp-shd volumio[708]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 19:04:10 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:10 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:10 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:10 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:10 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:11 minidsp-shd volumio[708]: info: Initializing connection to go-librespot Websocket Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="new websocket client" Mar 28 19:04:11 minidsp-shd volumio[708]: info: Connection to go-librespot Websocket established Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:04:11 minidsp-shd volumio[708]: info: Not Reporting Auto name since its the default one Mar 28 19:04:11 minidsp-shd volumio[708]: info: RAAT Overriding default device vendor model Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Mar 28 19:04:11 minidsp-shd sudo[1351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Mar 28 19:04:11 minidsp-shd sudo[1351]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:11 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Mar 28 19:04:11 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Mar 28 19:04:11 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Mar 28 19:04:11 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Mar 28 19:04:11 minidsp-shd systemd[1]: Started RAAT DAEMON. Mar 28 19:04:11 minidsp-shd sudo[1351]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="dealer connection closed" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="dealer recv loop stopped" Mar 28 19:04:11 minidsp-shd kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 28 19:04:11 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -113 Mar 28 19:04:11 minidsp-shd sudo[1261]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="obtained new client token: AADabmd3YovEzQ6Zd2d82XIfiQLLOGAemc+L/C4qg/8n5gsggxiVqTdt+XNFqCggEH9ZxThUza0NBNinuGpmzp5JbITSd0g4Ek2iHvSvr68d8l/CYNZPZnwL+TFNsrASaxpMhXqrpPMFTVdTYdMGQ/a3C4BvWatblm/IWtfvNeRB8IRmycBTpSWV3UegKYMUE2za1pCEmr4CDyHhE8d+0LNKL6UzXEUpEiWJfSeRguod0kl3fAdqkGXQFw==" Mar 28 19:04:11 minidsp-shd volumio[708]: info: Cannot mount NAS DiskStation at system boot, trial number 2 ,retrying in 5 seconds Mar 28 19:04:11 minidsp-shd volumio[708]: info: Raat Daemon started successfully Mar 28 19:04:11 minidsp-shd volumio[708]: info: Executing endpoint restartRAATSocket Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Mar 28 19:04:11 minidsp-shd volumio[708]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="completed keyexchange" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="completed challenge" Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=info msg="authenticated AP" username="ba*******lb" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=info msg="authenticated Login5" username="ba*******lb" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=info msg="accepted zeroconf from James Phone" username="ba*******lb" Mar 28 19:04:11 minidsp-shd sudo[1366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 28 19:04:11 minidsp-shd sudo[1366]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="dealer connection opened" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=trace msg="starting accesspoint recv loop" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=trace msg="starting dealer recv loop" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=trace msg="received accesspoint ping" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="received connection id: MDY1OWY2NmUtMjc0...QUNEMEVEOUQ1MQ==" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 19:04:11 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:11-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 19:04:11 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Mar 28 19:04:11 minidsp-shd volumio[708]: info: updateDSP function in raat called! Mar 28 19:04:12 minidsp-shd volumio[708]: info: Updating RAAT Signal Path Mar 28 19:04:12 minidsp-shd sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 28 19:04:12 minidsp-shd sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:04:12 minidsp-shd systemd[1]: Started MPD Monitor Service. Mar 28 19:04:12 minidsp-shd sudo[1366]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:12 minidsp-shd volumio[708]: info: Successfully started MPD Monitor Mar 28 19:04:12 minidsp-shd mpd_monitor.sh[1370]: MPD Monitor Service: Starting MPD Monitor Service Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="update volume requested to 55704/65535" Mar 28 19:04:12 minidsp-shd systemd[1]: Stopping MPD Monitor Service... Mar 28 19:04:12 minidsp-shd systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 19:04:12 minidsp-shd systemd[1]: mpd_monitor.service: Succeeded. Mar 28 19:04:12 minidsp-shd systemd[1]: Stopped MPD Monitor Service. Mar 28 19:04:12 minidsp-shd systemd[1]: Started MPD Monitor Service. Mar 28 19:04:12 minidsp-shd sudo[1369]: pam_unix(sudo:session): session closed for user root Mar 28 19:04:12 minidsp-shd volumio[708]: info: Successfully started MPD Monitor Mar 28 19:04:12 minidsp-shd mpd_monitor.sh[1374]: MPD Monitor Service: Starting MPD Monitor Service Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=trace msg="emitting websocket event: volume" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="handling transfer player command from 9fd43238f6290698638d41e75d66f75494efc6e4" Mar 28 19:04:12 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"volume","data":{"value":85,"max":100}} Mar 28 19:04:12 minidsp-shd volumio[708]: SPOTIFY: RECEIVED SPOTIFY VOLUME 85 Mar 28 19:04:12 minidsp-shd volumio[708]: info: Setting Volumio Volume from Spotify: 85 Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume Mar 28 19:04:12 minidsp-shd volumio[708]: info: msSurfaceDial volumioupdatevolume callback: {"vol":85,"dbVolume":-19,"mute":false,"disableVolumeControl":false} Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:12 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="resolved context of track" uri="spotify:album:4GzjQ0xXRlLl78ih481BUi" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=trace msg="fetched new page 0 with 8 items (list: 8)" uri="spotify:album:4GzjQ0xXRlLl78ih481BUi" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="loading track (paused: true, position: 151359ms)" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:12 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:12 minidsp-shd volumio[708]: info: Preload queue cleared Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=trace msg="emitting websocket event: will_play" Mar 28 19:04:12 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:4GzjQ0xXRlLl78ih481BUi","uri":"spotify:track:68d6ZfyMUYURol2y15Ta2Y","play_origin":"driving-jumpstart"}} Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="selected format OGG_VORBIS_320 (7433bec84400f4838423aa3683047e1fe99c2276)" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="requested aes key for file 7433bec84400f4838423aa3683047e1fe99c2276, gid: 68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1141" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=trace msg="received accesspoint pong ack" Mar 28 19:04:12 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:12-07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched first chunk of 56, total size is 29083344 bytes" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 1/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 13/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 14/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 2/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 3/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 12/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="seek to 151359ms (diff: 277ms, samples: 6674931, bytes: 6519878)" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="created new output device" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=info msg="loaded track \"Lingus\" (paused: true, position: 151359ms, duration: 645720ms, prefetched: false)" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="fetched chunk 15/55, size: 524288" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="emitting websocket event: metadata" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="emitting websocket event: active" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="sending successful reply for dealer request" Mar 28 19:04:13 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:68d6ZfyMUYURol2y15Ta2Y","name":"Lingus","artist_names":["Snarky Puppy"],"album_name":"We Like It Here","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a29d1ada28cf3d9d5fe1972d","position":151359,"duration":645720,"release_date":"year:2014 month:2 day:25","track_number":8,"disc_number":1}} Mar 28 19:04:13 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"active","data":null} Mar 28 19:04:13 minidsp-shd volumio[708]: info: Aligning Spotify Volume to Volumio Volume Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 28 19:04:13 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:13 minidsp-shd volumio[708]: info: Setting Spotify Volume from Volumio: 85 Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="emitting websocket event: paused" Mar 28 19:04:13 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:4GzjQ0xXRlLl78ih481BUi","uri":"spotify:track:68d6ZfyMUYURol2y15Ta2Y","play_origin":"driving-jumpstart"}} Mar 28 19:04:13 minidsp-shd volumio[708]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:04:13 minidsp-shd volumio[708]: TypeError: Cannot read property 'service' of undefined Mar 28 19:04:13 minidsp-shd volumio[708]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Mar 28 19:04:13 minidsp-shd volumio[708]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Mar 28 19:04:13 minidsp-shd volumio[708]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Mar 28 19:04:13 minidsp-shd volumio[708]: at WebSocket.emit (events.js:400:28) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.emit (events.js:400:28) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Mar 28 19:04:13 minidsp-shd volumio[708]: at writeOrBuffer (internal/streams/writable.js:358:12) Mar 28 19:04:13 minidsp-shd volumio[708]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Mar 28 19:04:13 minidsp-shd volumio[708]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Mar 28 19:04:13 minidsp-shd volumio[708]: at Socket.emit (events.js:400:28) Mar 28 19:04:13 minidsp-shd volumio[708]: at addChunk (internal/streams/readable.js:293:12) Mar 28 19:04:13 minidsp-shd volumio[708]: at readableAddChunk (internal/streams/readable.js:267:9) Mar 28 19:04:13 minidsp-shd volumio[708]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="handling resume player command from 9fd43238f6290698638d41e75d66f75494efc6e4" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="seek to 151359ms (diff: 277ms, samples: 6674931, bytes: 6519878)" uri="spotify:track:68d6ZfyMUYURol2y15Ta2Y" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 11609 us, period size = 512 frames, buffer time = 92879 us, buffer size = 4096 frames, periods per buffer = 8 frames, PCM format = FLOAT_LE" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="resume track at 151118ms" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="scheduling prefetch in 464s" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="sending successful reply for dealer request" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 28 19:04:13 minidsp-shd go-librespot[1239]: time="2026-03-28T19:04:13-07:00" level=trace msg="emitting websocket event: playing" Mar 28 19:04:14 minidsp-shd sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-28 19:03 Mar 28 19:04:14 minidsp-shd sudo[1402]: 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:27:40 PM CET" VOLUMIO_VERSION="3.877" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="861d146b0ca5e28d2e157bf87e6b15ea"