-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-12-28 10:46:51 CET. -- Dec 28 10:46:06 minidsp-shd systemd-timedated[847]: Changed local time to Sun Dec 28 10:46:06 2025 Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin ms_surface_dial to MyMusic Plugins Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin cd_controller to MyMusic Plugins Dec 28 10:46:06 minidsp-shd volumio-time-update[509]: volumio-time-update-util: System time updated successfully. Dec 28 10:46:06 minidsp-shd sudo[845]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin raat to MyMusic Plugins Dec 28 10:46:06 minidsp-shd systemd[1]: Starting Daily apt download activities... Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 28 10:46:06 minidsp-shd volumio[708]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 28 10:46:06 minidsp-shd systemd[1]: Started Volumio Time Update Utility. Dec 28 10:46:06 minidsp-shd volumio[708]: info: Loading plugins from folder /data/plugins/ Dec 28 10:46:06 minidsp-shd volumio[708]: info: Loading plugin "system"... Dec 28 10:46:06 minidsp-shd volumio[708]: info: Loading plugin "appearance"... Dec 28 10:46:06 minidsp-shd nmbd[647]: [2025/12/28 10:46:06.554524, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:46:06 minidsp-shd systemd[1]: Started Samba NMB Daemon. Dec 28 10:46:06 minidsp-shd nmbd[647]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 28 10:46:06 minidsp-shd systemd[1]: Starting Samba Winbind Daemon... Dec 28 10:46:06 minidsp-shd ntpd[810]: Soliciting pool server 51.68.44.27 Dec 28 10:46:06 minidsp-shd ntpd[810]: Soliciting pool server 162.159.200.123 Dec 28 10:46:07 minidsp-shd winbindd[867]: [2025/12/28 10:46:07.252108, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 28 10:46:07 minidsp-shd winbindd[867]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 28 10:46:07 minidsp-shd systemd[1]: Started Samba Winbind Daemon. Dec 28 10:46:07 minidsp-shd winbindd[867]: [2025/12/28 10:46:07.296273, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:46:07 minidsp-shd winbindd[867]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 28 10:46:07 minidsp-shd systemd[1]: Starting Samba SMB Daemon... Dec 28 10:46:07 minidsp-shd systemd[1]: apt-daily.service: Succeeded. Dec 28 10:46:07 minidsp-shd systemd[1]: Started Daily apt download activities. Dec 28 10:46:07 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... Dec 28 10:46:07 minidsp-shd volumio-remote-updater[497]: [2025-12-28 10:46:07] [connect] Successful connection Dec 28 10:46:07 minidsp-shd ntpd[810]: Soliciting pool server 164.132.166.29 Dec 28 10:46:07 minidsp-shd ntpd[810]: Soliciting pool server 51.68.180.114 Dec 28 10:46:07 minidsp-shd ntpd[810]: Soliciting pool server 45.90.162.253 Dec 28 10:46:08 minidsp-shd systemd[1]: Started Samba SMB Daemon. Dec 28 10:46:08 minidsp-shd smbd[895]: [2025/12/28 10:46:08.428636, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 28 10:46:08 minidsp-shd systemd[1]: Reached target Multi-User System. Dec 28 10:46:08 minidsp-shd smbd[895]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 28 10:46:08 minidsp-shd systemd[1]: Reached target Graphical Interface. Dec 28 10:46:08 minidsp-shd systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 28 10:46:08 minidsp-shd systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 28 10:46:08 minidsp-shd systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 28 10:46:08 minidsp-shd ntpd[810]: Soliciting pool server 82.67.41.119 Dec 28 10:46:08 minidsp-shd ntpd[810]: Soliciting pool server 38.242.218.253 Dec 28 10:46:08 minidsp-shd ntpd[810]: Soliciting pool server 195.154.185.215 Dec 28 10:46:09 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. Dec 28 10:46:09 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. Dec 28 10:46:09 minidsp-shd systemd[1]: Startup finished in 6.400s (kernel) + 18.959s (userspace) = 25.359s. Dec 28 10:46:09 minidsp-shd volumio[708]: info: Loading plugin "network"... Dec 28 10:46:09 minidsp-shd volumio[708]: info: Refreshing Cached IP Addresses Dec 28 10:46:09 minidsp-shd sudo[963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 28 10:46:09 minidsp-shd sudo[963]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:09 minidsp-shd sudo[965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 28 10:46:09 minidsp-shd sudo[963]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:09 minidsp-shd sudo[965]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:09 minidsp-shd volumio[708]: info: Loading plugin "services"... Dec 28 10:46:09 minidsp-shd volumio[708]: info: Loading plugin "alsa_controller"... Dec 28 10:46:09 minidsp-shd sudo[965]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:09 minidsp-shd sudo[975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 28 10:46:09 minidsp-shd sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:09 minidsp-shd sudo[975]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:09 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:46:09 minidsp-shd volumio[708]: info: Loading plugin "wizard"... Dec 28 10:46:09 minidsp-shd volumio[708]: info: Loading plugin "networkfs"... Dec 28 10:46:09 minidsp-shd volumio[708]: info: Starting Udev Watcher for removable devices Dec 28 10:46:09 minidsp-shd sudo[993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Fab&Mary,password=Sanra&Cie@69300,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.125/Musique /mnt/NAS/Nas_F&M Dec 28 10:46:09 minidsp-shd sudo[993]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:09 minidsp-shd ntpd[810]: Soliciting pool server 185.123.84.51 Dec 28 10:46:09 minidsp-shd ntpd[810]: Soliciting pool server 38.143.19.16 Dec 28 10:46:09 minidsp-shd ntpd[810]: Soliciting pool server 79.143.250.33 Dec 28 10:46:10 minidsp-shd kernel: FS-Cache: Loaded Dec 28 10:46:10 minidsp-shd volumio[708]: info: Ignoring mount for partition: BOOT Dec 28 10:46:10 minidsp-shd volumio[708]: info: Ignoring mount for partition: volumio Dec 28 10:46:10 minidsp-shd volumio[708]: info: Ignoring mount for partition: volumio_data Dec 28 10:46:10 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:46:10 minidsp-shd volumio[708]: info: Loading plugin "volumio_command_line_client"... Dec 28 10:46:10 minidsp-shd volumio[708]: info: Loading plugin "upnp"... Dec 28 10:46:10 minidsp-shd volumio[708]: info: [1766915170077] Starting Upmpd Daemon Dec 28 10:46:10 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:46:10 minidsp-shd volumio[708]: info: Loading plugin "my_music"... Dec 28 10:46:10 minidsp-shd volumio[708]: info: Loading plugin "mpd"... Dec 28 10:46:10 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching Dec 28 10:46:10 minidsp-shd kernel: Key type cifs.spnego registered Dec 28 10:46:10 minidsp-shd kernel: Key type cifs.idmap registered Dec 28 10:46:10 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.125/Musique Dec 28 10:46:10 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. Dec 28 10:46:10 minidsp-shd kernel: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 28 10:46:10 minidsp-shd kernel: CIFS VFS: \\192.168.1.125 Send error in SessSetup = -13 Dec 28 10:46:10 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Dec 28 10:46:10 minidsp-shd sudo[993]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:10 minidsp-shd volumio[708]: info: Loading plugin "upnp_browser"... Dec 28 10:46:10 minidsp-shd ntpd[810]: Soliciting pool server 82.66.40.79 Dec 28 10:46:10 minidsp-shd ntpd[810]: Soliciting pool server 2a01:cb00:129e:a803::137 Dec 28 10:46:10 minidsp-shd ntpd[810]: Soliciting pool server 5.196.76.84 Dec 28 10:46:11 minidsp-shd volumio[708]: info: Plugin bluetooth is not enabled Dec 28 10:46:11 minidsp-shd volumio[708]: info: Loading plugin "alarm-clock"... Dec 28 10:46:11 minidsp-shd ntpd[810]: Soliciting pool server 82.67.62.62 Dec 28 10:46:12 minidsp-shd volumio[708]: info: Loading plugin "manifestui"... Dec 28 10:46:12 minidsp-shd volumio[708]: info: Loading plugin "metavolumio"... Dec 28 10:46:12 minidsp-shd ntpd[810]: Soliciting pool server 82.65.248.56 Dec 28 10:46:13 minidsp-shd ntpd[810]: Soliciting pool server 109.190.177.200 Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f4a3512c does not match aorg 0000000000.00000000 from server@164.132.166.29 xmt 0xecfb7ae8.63a33a74 Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f4a78bf5 does not match aorg 0000000000.00000000 from server@37.59.63.125 xmt 0xecfb7ae8.6385d9f4 Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f4746fcf does not match aorg 0000000000.00000000 from server@79.143.250.33 xmt 0xecfb7ae8.63879259 Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f48600c4 does not match aorg 0000000000.00000000 from server@185.123.84.51 xmt 0xecfb7ae8.63a15a21 Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f49b1cd0 does not match aorg 0000000000.00000000 from server@38.242.218.253 xmt 0xecfb7ae8.63d7353e Dec 28 10:46:16 minidsp-shd ntpd[810]: receive: Unexpected origin timestamp 0xecfb7ae6.f4a133c0 does not match aorg 0000000000.00000000 from server@51.68.180.114 xmt 0xecfb7ae8.6439ee50 Dec 28 10:46:16 minidsp-shd volumio[708]: info: Plugin airplay_emulation is not enabled Dec 28 10:46:16 minidsp-shd volumio[708]: info: Loading plugin "cd_controller"... Dec 28 10:46:17 minidsp-shd volumio[708]: info: Loading plugin "last_100"... Dec 28 10:46:17 minidsp-shd volumio[708]: info: Loading plugin "qobuzconnect"... Dec 28 10:46:17 minidsp-shd volumio[708]: info: Plugin raat is not enabled Dec 28 10:46:17 minidsp-shd volumio[708]: info: Loading plugin "streaming_services"... Dec 28 10:46:19 minidsp-shd volumio[708]: info: Starting Streaming Service Transparent Proxy Dec 28 10:46:19 minidsp-shd volumio[708]: info: Plugin tidalconnect is not enabled Dec 28 10:46:19 minidsp-shd volumio[708]: info: Loading plugin "webradio"... Dec 28 10:46:19 minidsp-shd volumio[708]: info: Loading plugin "i2s_dacs"... Dec 28 10:46:20 minidsp-shd volumio[708]: info: I2S DAC not set, start Auto-detection Dec 28 10:46:20 minidsp-shd volumio[708]: info: Loading plugin "volumiodiscovery"... Dec 28 10:46:20 minidsp-shd volumio[708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 28 10:46:20 minidsp-shd volumio[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:46:20 minidsp-shd node[708]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 28 10:46:20 minidsp-shd volumio[708]: *** WARNING *** For more information see Dec 28 10:46:20 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. Dec 28 10:46:20 minidsp-shd volumio[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:46:20 minidsp-shd volumio[708]: *** WARNING *** For more information see Dec 28 10:46:20 minidsp-shd node[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:46:20 minidsp-shd node[708]: *** WARNING *** For more information see Dec 28 10:46:20 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. Dec 28 10:46:20 minidsp-shd node[708]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 28 10:46:20 minidsp-shd node[708]: *** WARNING *** For more information see Dec 28 10:46:20 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 28 10:46:20 minidsp-shd volumio[708]: info: Discovery: Started advertising with name: MiniDsp SHD Dec 28 10:46:20 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 28 10:46:20 minidsp-shd volumio[708]: info: Loading plugin "spop"... Dec 28 10:46:21 minidsp-shd volumio[708]: STREAMING PROXY: Starting server on port 3245 Dec 28 10:46:21 minidsp-shd volumio[708]: Node JS runtime: 14 Dec 28 10:46:23 minidsp-shd volumio[708]: info: Plugin multiroom is not enabled Dec 28 10:46:23 minidsp-shd volumio[708]: info: Loading plugin "outputs"... Dec 28 10:46:23 minidsp-shd volumio[708]: info: Loading plugin "albumart"... Dec 28 10:46:23 minidsp-shd volumio[708]: info: Plugin ms_surface_dial is not enabled Dec 28 10:46:23 minidsp-shd volumio[708]: info: Plugin example_plugin is not enabled Dec 28 10:46:23 minidsp-shd volumio[708]: info: Loading plugin "hi_res_audio"... Dec 28 10:46:24 minidsp-shd volumio[708]: Forking 3 albumart workers Dec 28 10:46:24 minidsp-shd volumio-remote-updater[497]: [2025-12-28 10:46:24] [connect] Successful connection Dec 28 10:46:24 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. Dec 28 10:46:25 minidsp-shd volumio[708]: Starting albumart workers Dec 28 10:46:26 minidsp-shd volumio[708]: Starting albumart workers Dec 28 10:46:26 minidsp-shd volumio[708]: Starting albumart workers Dec 28 10:46:26 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin hi_res_audio Dec 28 10:46:26 minidsp-shd volumio[708]: info: Loading plugin "inputs"... Dec 28 10:46:28 minidsp-shd volumio[708]: info: Loading plugin "qobuz"... Dec 28 10:46:31 minidsp-shd volumio[708]: info: Loading plugin "tidal"... Dec 28 10:46:33 minidsp-shd volumio[708]: info: Loading plugin "oem_helper"... Dec 28 10:46:35 minidsp-shd volumio[708]: info: Applying required configuration parameters for plugin oem_helper Dec 28 10:46:35 minidsp-shd volumio[708]: info: Loading plugin "updater_comm"... Dec 28 10:46:35 minidsp-shd volumio[708]: info: Plugin mpdemulation is not enabled Dec 28 10:46:35 minidsp-shd volumio[708]: info: Loading plugin "rest_api"... Dec 28 10:46:35 minidsp-shd volumio[708]: info: Loading plugin "websocket"... Dec 28 10:46:35 minidsp-shd volumio[708]: info: Starting Socket.io Server version 2.3.0 Dec 28 10:46:35 minidsp-shd volumio[708]: info: Loading i18n strings for locale fr Dec 28 10:46:35 minidsp-shd volumio[708]: Updating browse sources language Dec 28 10:46:35 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::initPlayerControls Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:46:36 minidsp-shd volumio[708]: Express server listening on port 3000 Dec 28 10:46:36 minidsp-shd volumio[708]: [Metrics] WebUI: 32s 908.87ms Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreStateMachine::resetVolumioState Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreStateMachine::getcurrentVolume Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:36 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:36 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:36 minidsp-shd sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 28 10:46:36 minidsp-shd sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:36 minidsp-shd sudo[1120]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:36 minidsp-shd sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 28 10:46:36 minidsp-shd sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:36 minidsp-shd volumio[708]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Dec 28 10:46:36 minidsp-shd volumio[708]: info: Completed loading Core Plugins Dec 28 10:46:36 minidsp-shd volumio[708]: info: Preparing to generate the ALSA configuration file Dec 28 10:46:36 minidsp-shd sudo[1122]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:36 minidsp-shd volumio[708]: info: Volumio Network Manager: Network status updated: 1 Dec 28 10:46:36 minidsp-shd volumio[708]: info: Cannot mount NAS Nas_F&M at system boot, trial number 1 ,retrying in 5 seconds Dec 28 10:46:36 minidsp-shd volumio[708]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Dec 28 10:46:36 minidsp-shd volumio[708]: wlan0 Interface doesn't support scanning. Dec 28 10:46:36 minidsp-shd volumio[708]: info: Cannot use regular scanning, forcing with ap-force Dec 28 10:46:36 minidsp-shd sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Dec 28 10:46:36 minidsp-shd sudo[1128]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:36 minidsp-shd sudo[1128]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:36 minidsp-shd volumio[708]: command failed: No such device (-19) Dec 28 10:46:36 minidsp-shd volumio[708]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Dec 28 10:46:36 minidsp-shd volumio[708]: command failed: No such device (-19) Dec 28 10:46:36 minidsp-shd volumio[708]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Dec 28 10:46:37 minidsp-shd volumio[708]: info: Reloading queue from file Dec 28 10:46:37 minidsp-shd volumio[708]: info: Asound.conf file unchanged, so no further update is needed Dec 28 10:46:37 minidsp-shd volumio[708]: info: Output device has changed, restarting MPD Dec 28 10:46:37 minidsp-shd sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 28 10:46:37 minidsp-shd sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd volumio[708]: info: ___________ START PLUGINS ___________ Dec 28 10:46:37 minidsp-shd sudo[1138]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:37 minidsp-shd volumio[708]: info: ControllerMpd::onStart: Initializing MPD Dec 28 10:46:37 minidsp-shd volumio[708]: info: Creating MPD Configuration file Dec 28 10:46:37 minidsp-shd sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 28 10:46:37 minidsp-shd sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd systemd[1]: systemd-timedated.service: Succeeded. Dec 28 10:46:37 minidsp-shd systemd[1]: Listening on mpd.socket. Dec 28 10:46:37 minidsp-shd sudo[1144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 28 10:46:37 minidsp-shd sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:37 minidsp-shd volumio[708]: info: [1766915197536] CoreMusicLibrary::Adding element Serveurs Média Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:37 minidsp-shd sudo[1144]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:37 minidsp-shd systemd[1]: Starting Music Player Daemon... Dec 28 10:46:37 minidsp-shd sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 28 10:46:37 minidsp-shd sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Dec 28 10:46:37 minidsp-shd systemd[1]: mpd.service: Succeeded. Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding METAVOLUMIO REST API Endpoints Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:46:37 minidsp-shd systemd[1]: Stopped Music Player Daemon. Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 28 10:46:37 minidsp-shd volumio[708]: info: Preparing CD Folders Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding CD REST API Endpoints Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 28 10:46:37 minidsp-shd systemd[1]: Starting Music Player Daemon... Dec 28 10:46:37 minidsp-shd volumio[708]: info: Starting UDEV Watcher for CD Dec 28 10:46:37 minidsp-shd volumio[708]: info: Detecting CD presence with UDEV Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:37 minidsp-shd volumio[708]: info: [1766915197683] CoreMusicLibrary::Adding element Last_100 Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:37 minidsp-shd volumio[708]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:37 minidsp-shd volumio[708]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 28 10:46:37 minidsp-shd volumio[708]: info: Streaming services startup Dec 28 10:46:37 minidsp-shd volumio[708]: info: Starting Streaming Daemon Dec 28 10:46:37 minidsp-shd sudo[1157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 28 10:46:37 minidsp-shd sudo[1152]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 28 10:46:37 minidsp-shd sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd sudo[1157]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd sudo[1152]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 28 10:46:37 minidsp-shd sudo[1152]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:37 minidsp-shd sudo[1161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 28 10:46:37 minidsp-shd sudo[1161]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd sudo[1157]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:37 minidsp-shd sudo[1161]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:37 minidsp-shd sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 28 10:46:37 minidsp-shd sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:37 minidsp-shd volumio[708]: info: [1766915197957] CoreMusicLibrary::Adding element Webradio Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:37 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:46:37 minidsp-shd volumio[708]: info: Initializing BBC Radios Dec 28 10:46:38 minidsp-shd systemd[1]: Started Volumio Qobuz Connect Service. Dec 28 10:46:38 minidsp-shd sudo[1165]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:38 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:46:38 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:38 minidsp-shd volumio[708]: info: Creating Spotify config file Dec 28 10:46:38 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:38 minidsp-shd volumio[708]: error: Hi Res Audio Failed Login: Missing Login Data Dec 28 10:46:38 minidsp-shd volumio[708]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 28 10:46:38 minidsp-shd volumio[708]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 28 10:46:38 minidsp-shd volumio[708]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 28 10:46:38 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:46:38 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:38 minidsp-shd volumio[708]: info: Volumio Calling Home Dec 28 10:46:38 minidsp-shd volumio[708]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 28 10:46:38 minidsp-shd volumio[708]: info: Stopping AccessToken refresher cron for QOBUZ Dec 28 10:46:38 minidsp-shd volumio[708]: info: AccessToken refresher cron started for QOBUZ Dec 28 10:46:38 minidsp-shd volumio[708]: info: Adding TIDAL REST API Endpoints Dec 28 10:46:38 minidsp-shd volumio[708]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Dec 28 10:46:39 minidsp-shd volumio[708]: info: Adding QOBUZ REST API Endpoints Dec 28 10:46:39 minidsp-shd volumio[708]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Dec 28 10:46:39 minidsp-shd volumio[708]: info: Setting Device type: NanoPi NEO 3 Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreStateMachine::setRepeat null single undefined Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreStateMachine::setRandom false Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:39 minidsp-shd volumio-remote-updater[497]: [2025-12-28 10:46:39] [connect] Successful connection Dec 28 10:46:39 minidsp-shd volumio[708]: info: Serial port opened successfully Dec 28 10:46:39 minidsp-shd volumio[708]: error: Cannot start Volumio Streaming Daemon Dec 28 10:46:39 minidsp-shd volumio[708]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 28 10:46:39 minidsp-shd volumio[708]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 28 10:46:39 minidsp-shd volumio[708]: info: MPD Permissions set Dec 28 10:46:39 minidsp-shd volumio[708]: info: MPD Permissions set Dec 28 10:46:39 minidsp-shd sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 28 10:46:39 minidsp-shd sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:39 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. Dec 28 10:46:39 minidsp-shd sudo[1196]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:39 minidsp-shd volumio[708]: info: Executing endpoint qc_getconfig Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.744 [1171.1171] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 28 10:46:39 minidsp-shd volumio-remote-updater[497]: [2025-12-28 10:46:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1766915199 101 Dec 28 10:46:39 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: 1 Dec 28 10:46:39 minidsp-shd volumio[708]: info: Volumio called home Dec 28 10:46:39 minidsp-shd volumio[708]: info: Spotify config file written Dec 28 10:46:39 minidsp-shd volumio[708]: info: Discovery: adding 49f234a6-9249-4595-baf6-dd291b72f25f Dec 28 10:46:39 minidsp-shd volumio[708]: info: Discovery: Found device MiniDsp SHD Dec 28 10:46:39 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:39 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.928 [1171.1171] INFO VolumeManager: [0xcc59f8]: Setting new playback volume: 75 Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.928 [1171.1171] INFO VolumeManager: [0xcc59f8]: Setting new mute state: 0 Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.928 [1171.1171] INFO QobuzConnect: [0xcc63c8]: Client initialized! Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.928 [1171.1171] INFO SampleApp: Starting Avahi advertising, name: MiniDsp SHD, service name: _qobuz-connect._tcp Dec 28 10:46:39 minidsp-shd sudo[1202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 28 10:46:39 minidsp-shd sudo[1202]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.965 [1171.1171] INFO LocalConfigManager: [0xcc52d8]: Starting Local Configuration server Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.965 [1171.1171] INFO SampleApp: Starting Local configuration server Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.966 [1171.1171] INFO SampleApp: Playback volume changed: 75 Dec 28 10:46:39 minidsp-shd qobuz-connect[1171]: 20251228 10:46:39.967 [1171.1171] INFO SampleApp: Connected to UNIX socket client 0xcbaed8 Dec 28 10:46:40 minidsp-shd systemd[1]: Started go-librespot Daemon. Dec 28 10:46:40 minidsp-shd sudo[1202]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:40 minidsp-shd go-librespot[1205]: go-librespot daemon starting... Dec 28 10:46:40 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:40+01:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:46:40 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:40+01:00" level=debug msg="app state loaded" Dec 28 10:46:40 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:46:40 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: 2 Dec 28 10:46:40 minidsp-shd volumio[708]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 28 10:46:40 minidsp-shd volumio[708]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 28 10:46:40 minidsp-shd volumio[708]: info: Upmpdcli Daemon Started Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=info msg="zeroconf server listening on port 44357" Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: No need to fix Spotify hosts Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="obtained new client token: AADpWsKE3dF94QhHo/Sj7jogBpIy8Brm7/awEcil5/l3X5wf6p7Z7X+6kxVDtE7WjGuo4i4kk5WNu6Ack/g3c5GCpyHwuLEfzPuQNaH6Bm2HfliPAdvqOomJqtjJeP/86v6gKm+Tl6ETfbVtDab2Wn/wWmxZ0VgPqzH0ioNo2ZZb1EFgtx+TANqcb/48y5euBhvht+DOpBPAd5CKjAAZeAg05gKjaqvhQdYXrxmWLP8zx+yuURpmAAA=" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="completed keyexchange" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="completed challenge" Dec 28 10:46:41 minidsp-shd volumio[708]: info: Adding MINIDSP Inputs Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:41 minidsp-shd volumio[708]: info: [1766915201368] CoreMusicLibrary::Adding element Inputs Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:41 minidsp-shd volumio[708]: info: [1766915201382] CoreMusicLibrary::Adding element Presets Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:41 minidsp-shd volumio[708]: Cannot find translation for source Presets Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=info msg="authenticated AP" username="11******97" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=info msg="authenticated Login5" username="11******97" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="initializing zeroconf session" username="11******97" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="dealer connection opened" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=trace msg="starting accesspoint recv loop" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=trace msg="starting dealer recv loop" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=trace msg="received accesspoint ping" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="received connection id: YjRjOTg2NDUtYzU0...RDdGRTVGM0M2RA==" Dec 28 10:46:41 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=trace msg="received accesspoint pong ack" Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 28 10:46:41 minidsp-shd volumio[708]: info: Enabling external Volume Control Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::volumiosetSourceActiveno-source Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:41 minidsp-shd volumio[708]: Cannot find translation for source Presets Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="update volume requested to 51117/65535" Dec 28 10:46:41 minidsp-shd volumio[708]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:46:41 minidsp-shd volumio[708]: SPOTIFY: BQDoKp3xhYzMiRIZeBd5-7O3kRjyPXXd8gPJFwXO4smA5we3F29gUgsH1zQfSSH3jHqyv74WycnwXAMxGFy6ZBv0M6_xsIIwMG78GWG0YYckY-CyJm_w3ahv5ZWXfNioeHhgKfCMGxHhrIbRs5FH_LCyYzb5E73UFoBkB_h3Ru1ZPs0qldn1b3CieNcICMV1PmmV-BMY54qqDDdD0piHLmmf1YMZhU5fWva79RyPOiwE2vfwRka24T6D4mPNp5VM5gpLisrfV1EiTlcuNJw0z2WPuDG5JMnUcP7A Dec 28 10:46:41 minidsp-shd volumio[708]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:46:41 minidsp-shd volumio[708]: info: New Spotify access token = BQDoKp3xhYzMiRIZeBd5-7O3kRjyPXXd8gPJFwXO4smA5we3F29gUgsH1zQfSSH3jHqyv74WycnwXAMxGFy6ZBv0M6_xsIIwMG78GWG0YYckY-CyJm_w3ahv5ZWXfNioeHhgKfCMGxHhrIbRs5FH_LCyYzb5E73UFoBkB_h3Ru1ZPs0qldn1b3CieNcICMV1PmmV-BMY54qqDDdD0piHLmmf1YMZhU5fWva79RyPOiwE2vfwRka24T6D4mPNp5VM5gpLisrfV1EiTlcuNJw0z2WPuDG5JMnUcP7A Dec 28 10:46:41 minidsp-shd volumio[708]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 28 10:46:41 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 Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 28 10:46:41 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:41+01:00" level=trace msg="emitting websocket event: volume" Dec 28 10:46:41 minidsp-shd sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Fab&Mary,password=Sanra&Cie@69300,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.125/Musique /mnt/NAS/Nas_F&M Dec 28 10:46:41 minidsp-shd sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:41 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:41 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:41 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.125/Musique Dec 28 10:46:41 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. Dec 28 10:46:41 minidsp-shd kernel: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 28 10:46:41 minidsp-shd kernel: CIFS VFS: \\192.168.1.125 Send error in SessSetup = -13 Dec 28 10:46:41 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Dec 28 10:46:42 minidsp-shd sudo[1242]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:42 minidsp-shd volumio[708]: info: Cannot mount NAS Nas_F&M at system boot, trial number 2 ,retrying in 5 seconds Dec 28 10:46:42 minidsp-shd volumio[708]: SPOTIFY: User informations: {"country":"FR","display_name":"Cybermeu","email":"cybermeu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1150051497"},"followers":{"href":null,"total":4},"href":"https://api.spotify.com/v1/users/1150051497","id":"1150051497","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85b7954d2f26adedce63a71b86","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82b7954d2f26adedce63a71b86","width":64}],"product":"premium","type":"user","uri":"spotify:user:1150051497"} Dec 28 10:46:42 minidsp-shd volumio[708]: info: Spotify Successfully logged in Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:46:42 minidsp-shd volumio[708]: info: [1766915202366] CoreMusicLibrary::Adding element Spotify Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:46:42 minidsp-shd volumio[708]: Cannot find translation for source Presets Dec 28 10:46:42 minidsp-shd volumio[708]: Cannot find translation for source Spotify Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:42 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:42 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:42 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:43 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:43 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:43 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:43 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:43 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:43 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:43 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Dec 28 10:46:43 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 Dec 28 10:46:44 minidsp-shd mpd[1162]: Dec 28 10:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 28 10:46:44 minidsp-shd systemd[1]: Started Music Player Daemon. Dec 28 10:46:44 minidsp-shd volumio[708]: Upnp client error: Error: This socket has been ended by the other party Dec 28 10:46:44 minidsp-shd sudo[1148]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:44 minidsp-shd sudo[1140]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:44 minidsp-shd volumio[708]: info: Completed starting Core Plugins Dec 28 10:46:44 minidsp-shd volumio[708]: info: ------------------------------------------- Dec 28 10:46:44 minidsp-shd volumio[708]: info: ----- MyVolumio plugins startup ---- Dec 28 10:46:44 minidsp-shd volumio[708]: info: ------------------------------------------- Dec 28 10:46:44 minidsp-shd volumio[708]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 28 10:46:44 minidsp-shd volumio[708]: error: MPD error: The expression evaluated to a falsy value: Dec 28 10:46:44 minidsp-shd volumio[708]: assert.ok(self.idling) Dec 28 10:46:44 minidsp-shd volumio[708]: error: The expression evaluated to a falsy value: Dec 28 10:46:44 minidsp-shd volumio[708]: assert.ok(self.idling) Dec 28 10:46:44 minidsp-shd volumio[708]: info: MPD running with PID1162 Dec 28 10:46:44 minidsp-shd volumio[708]: ,establishing connection Dec 28 10:46:44 minidsp-shd volumio[708]: error: updateQueue error: null Dec 28 10:46:44 minidsp-shd volumio[708]: error: updateQueue error: null Dec 28 10:46:44 minidsp-shd volumio[1198]: Generating RSA private key, 4096 bit long modulus (2 primes) Dec 28 10:46:44 minidsp-shd volumio[708]: info: go-librespot daemon successfully initialized Dec 28 10:46:46 minidsp-shd volumio[1198]: .........................++++ Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="handling transfer player command from 588f14b4b37de11a8e998766bcac16689ab1ed48" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="resolved context of track" uri="spotify:album:0gv09X6sIqISSEyZUVznrD" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="fetched new page 0 with 24 items (list: 24)" uri="spotify:album:0gv09X6sIqISSEyZUVznrD" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="loading track (paused: true, position: 7782ms)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="emitting websocket event: will_play" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="selected format OGG_VORBIS_320 (0c60c109e9eb9143b5a6e87eb8ce941acb2b6303)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="requested aes key for file 0c60c109e9eb9143b5a6e87eb8ce941acb2b6303, gid: 12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1280" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd sudo[1267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Fab&Mary,password=Sanra&Cie@69300,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.125/Musique /mnt/NAS/Nas_F&M Dec 28 10:46:47 minidsp-shd sudo[1267]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:47 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.125/Musique Dec 28 10:46:47 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. Dec 28 10:46:47 minidsp-shd kernel: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 28 10:46:47 minidsp-shd kernel: CIFS VFS: \\192.168.1.125 Send error in SessSetup = -13 Dec 28 10:46:47 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Dec 28 10:46:47 minidsp-shd sudo[1267]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:47 minidsp-shd volumio[708]: info: Cannot mount NAS Nas_F&M at system boot, trial number 3 ,retrying in 5 seconds Dec 28 10:46:47 minidsp-shd sudo[1273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 28 10:46:47 minidsp-shd sudo[1273]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="fetched first chunk of 23, total size is 11612606 bytes" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="seek to 7782ms (diff: 124ms, samples: 343186, bytes: 276379)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="created new output device" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=info msg="loaded track \"Le penseur\" (paused: true, position: 7782ms, duration: 244480ms, prefetched: false)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="emitting websocket event: metadata" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="emitting websocket event: active" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="sending successful reply for dealer request" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 28 10:46:47 minidsp-shd sudo[1276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 28 10:46:47 minidsp-shd systemd[1]: Started MPD Monitor Service. Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=trace msg="emitting websocket event: paused" Dec 28 10:46:47 minidsp-shd sudo[1273]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:47 minidsp-shd sudo[1276]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 10:46:47 minidsp-shd volumio[708]: info: Successfully started MPD Monitor Dec 28 10:46:47 minidsp-shd mpd_monitor.sh[1278]: MPD Monitor Service: Starting MPD Monitor Service Dec 28 10:46:47 minidsp-shd systemd[1]: Stopping MPD Monitor Service... Dec 28 10:46:47 minidsp-shd systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 28 10:46:47 minidsp-shd systemd[1]: mpd_monitor.service: Succeeded. Dec 28 10:46:47 minidsp-shd systemd[1]: Stopped MPD Monitor Service. Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd systemd[1]: Started MPD Monitor Service. Dec 28 10:46:47 minidsp-shd sudo[1276]: pam_unix(sudo:session): session closed for user root Dec 28 10:46:47 minidsp-shd volumio[708]: info: Initializing connection to go-librespot Websocket Dec 28 10:46:47 minidsp-shd mpd_monitor.sh[1282]: MPD Monitor Service: Starting MPD Monitor Service Dec 28 10:46:47 minidsp-shd volumio[708]: info: Successfully started MPD Monitor Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="new websocket client" Dec 28 10:46:47 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:47+01:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:47 minidsp-shd volumio[708]: info: Connection to go-librespot Websocket established Dec 28 10:46:48 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=debug msg="handling seek_to player command from 588f14b4b37de11a8e998766bcac16689ab1ed48" Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=debug msg="seek track to 0ms" Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=trace msg="emitting websocket event: seek" Dec 28 10:46:49 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:49+01:00" level=debug msg="sending successful reply for dealer request" Dec 28 10:46:49 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"seek","data":{"context_uri":"spotify:album:0gv09X6sIqISSEyZUVznrD","uri":"spotify:track:12Dj07GLbYhSa7u3xGrD7W","position":0,"duration":244480,"play_origin":""}} Dec 28 10:46:49 minidsp-shd volumio[708]: SPOTIFY: PUSH STATE SPOTIFY Dec 28 10:46:49 minidsp-shd volumio[708]: SPOTIFY: {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::servicePushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 28 10:46:49 minidsp-shd volumio[708]: verbose: CURRENT POSITION 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreStateMachine::syncState stateService stop Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: No code Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreStateMachine::pushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioPushState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CoreCommandRouter::volumioGetState Dec 28 10:46:49 minidsp-shd volumio[708]: info: CorePlayQueue::getTrack 0 Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="handling resume player command from 588f14b4b37de11a8e998766bcac16689ab1ed48" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="vorbis: corrupt or missing data in bitstream" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:12Dj07GLbYhSa7u3xGrD7W" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 23219 us, period size = 1024 frames, buffer time = 92879 us, buffer size = 4096 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="resume track at 0ms" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=trace msg="scheduling prefetch in 214s" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="sending successful reply for dealer request" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 28 10:46:50 minidsp-shd go-librespot[1205]: time="2025-12-28T10:46:50+01:00" level=trace msg="emitting websocket event: playing" Dec 28 10:46:50 minidsp-shd volumio[708]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:0gv09X6sIqISSEyZUVznrD","uri":"spotify:track:12Dj07GLbYhSa7u3xGrD7W","resume":true,"play_origin":""}} Dec 28 10:46:50 minidsp-shd volumio[708]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:46:50 minidsp-shd volumio[708]: TypeError: Cannot read property 'service' of undefined Dec 28 10:46:50 minidsp-shd volumio[708]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Dec 28 10:46:50 minidsp-shd volumio[708]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Dec 28 10:46:50 minidsp-shd volumio[708]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Dec 28 10:46:50 minidsp-shd volumio[708]: at WebSocket.emit (events.js:400:28) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.emit (events.js:400:28) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 28 10:46:50 minidsp-shd volumio[708]: at writeOrBuffer (internal/streams/writable.js:358:12) Dec 28 10:46:50 minidsp-shd volumio[708]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Dec 28 10:46:50 minidsp-shd volumio[708]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Dec 28 10:46:50 minidsp-shd volumio[708]: at Socket.emit (events.js:400:28) Dec 28 10:46:50 minidsp-shd volumio[708]: at addChunk (internal/streams/readable.js:293:12) Dec 28 10:46:50 minidsp-shd volumio[708]: at readableAddChunk (internal/streams/readable.js:267:9) Dec 28 10:46:50 minidsp-shd volumio[708]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:46:51 minidsp-shd volumio[1198]: ...........................................................++++ Dec 28 10:46:51 minidsp-shd volumio[1198]: e is 65537 (0x010001) Dec 28 10:46:51 minidsp-shd volumio[1198]: writing RSA key Dec 28 10:46:51 minidsp-shd sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-28 10:45 Dec 28 10:46:51 minidsp-shd sudo[1305]: 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"