-- Logs begin at Thu 2019-02-14 04:11:59 CST, end at Fri 2026-02-06 17:18:02 CST. --
Feb 06 17:17:18 shd systemd-timedated[841]: Changed local time to Fri Feb 6 17:17:18 2026
Feb 06 17:17:18 shd sudo[810]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:18 shd volumio-time-update[526]: volumio-time-update-util: System time updated successfully.
Feb 06 17:17:18 shd systemd[1]: Starting Daily apt download activities...
Feb 06 17:17:18 shd systemd[1]: Started Volumio Time Update Utility.
Feb 06 17:17:18 shd nmbd[655]: [2026/02/06 17:17:18.411147, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Feb 06 17:17:18 shd systemd[1]: Started Samba NMB Daemon.
Feb 06 17:17:18 shd nmbd[655]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections
Feb 06 17:17:18 shd systemd[1]: Starting Samba Winbind Daemon...
Feb 06 17:17:18 shd ntpd[819]: Soliciting pool server 216.66.48.42
Feb 06 17:17:19 shd winbindd[856]: [2026/02/06 17:17:19.092658, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache)
Feb 06 17:17:19 shd winbindd[856]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Feb 06 17:17:19 shd winbindd[856]: [2026/02/06 17:17:19.122831, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Feb 06 17:17:19 shd winbindd[856]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections
Feb 06 17:17:19 shd systemd[1]: Started Samba Winbind Daemon.
Feb 06 17:17:19 shd systemd[1]: Starting Samba SMB Daemon...
Feb 06 17:17:19 shd volumio-remote-updater[519]: [2026-02-06 17:17:19] [connect] Successful connection
Feb 06 17:17:19 shd ntpd[819]: Soliciting pool server 162.244.81.139
Feb 06 17:17:19 shd ntpd[819]: Soliciting pool server 172.233.155.39
Feb 06 17:17:19 shd systemd[1]: apt-daily.service: Succeeded.
Feb 06 17:17:19 shd systemd[1]: Started Daily apt download activities.
Feb 06 17:17:19 shd systemd[1]: Starting Daily apt upgrade and clean activities...
Feb 06 17:17:20 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:20 shd volumio[716]: info: ----- Volumio3 ----
Feb 06 17:17:20 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:20 shd volumio[716]: info: ----- System startup ----
Feb 06 17:17:20 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:20 shd systemd[1]: Started Samba SMB Daemon.
Feb 06 17:17:20 shd smbd[888]: [2026/02/06 17:17:20.285562, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Feb 06 17:17:20 shd systemd[1]: Reached target Multi-User System.
Feb 06 17:17:20 shd smbd[888]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
Feb 06 17:17:20 shd systemd[1]: Reached target Graphical Interface.
Feb 06 17:17:20 shd systemd[1]: Starting Update UTMP about System Runlevel Changes...
Feb 06 17:17:20 shd systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Feb 06 17:17:20 shd systemd[1]: Started Update UTMP about System Runlevel Changes.
Feb 06 17:17:20 shd ntpd[819]: Soliciting pool server 138.68.201.49
Feb 06 17:17:20 shd ntpd[819]: Soliciting pool server 172.104.28.175
Feb 06 17:17:20 shd ntpd[819]: Soliciting pool server 172.233.153.85
Feb 06 17:17:21 shd systemd[1]: apt-daily-upgrade.service: Succeeded.
Feb 06 17:17:21 shd systemd[1]: Started Daily apt upgrade and clean activities.
Feb 06 17:17:21 shd systemd[1]: Startup finished in 5.746s (kernel) + 19.022s (userspace) = 24.768s.
Feb 06 17:17:21 shd ntpd[819]: Soliciting pool server 172.235.60.8
Feb 06 17:17:21 shd ntpd[819]: Soliciting pool server 173.255.255.133
Feb 06 17:17:21 shd ntpd[819]: Soliciting pool server 23.186.168.126
Feb 06 17:17:21 shd ntpd[819]: Soliciting pool server 170.187.147.56
Feb 06 17:17:22 shd volumio[716]: info: MYVOLUMIO Environment detected
Feb 06 17:17:22 shd volumio[716]: info: Plugin folders cleanup
Feb 06 17:17:22 shd volumio[716]: info: Scanning into folder /volumio/app/plugins/
Feb 06 17:17:22 shd volumio[716]: info: Scanning category audio_interface
Feb 06 17:17:22 shd volumio[716]: info: Scanning category miscellanea
Feb 06 17:17:22 shd volumio[716]: info: Scanning category music_service
Feb 06 17:17:22 shd volumio[716]: info: Scanning category plugins.json
Feb 06 17:17:22 shd volumio[716]: info: Scanning category system_controller
Feb 06 17:17:22 shd volumio[716]: info: Scanning category user_interface
Feb 06 17:17:22 shd volumio[716]: info: Scanning into folder /data/plugins/
Feb 06 17:17:22 shd volumio[716]: info: Scanning category music_service
Feb 06 17:17:22 shd volumio[716]: info: Plugin folders cleanup completed
Feb 06 17:17:22 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:22 shd volumio[716]: info: ----- Core plugins startup ----
Feb 06 17:17:22 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:22 shd volumio[716]: info: Loading plugins from folder /volumio/app/plugins/
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin multiroom to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin upnp to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin ms_surface_dial to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin raat to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 06 17:17:22 shd volumio[716]: info: Loading plugins from folder /data/plugins/
Feb 06 17:17:22 shd volumio[716]: info: Loading plugin "system"...
Feb 06 17:17:22 shd ntpd[819]: Soliciting pool server 50.218.103.254
Feb 06 17:17:22 shd ntpd[819]: Soliciting pool server 162.159.200.1
Feb 06 17:17:22 shd ntpd[819]: Soliciting pool server 23.186.168.123
Feb 06 17:17:22 shd volumio[716]: info: Loading plugin "appearance"...
Feb 06 17:17:23 shd ntpd[819]: Soliciting pool server 23.186.168.127
Feb 06 17:17:23 shd ntpd[819]: Soliciting pool server 72.30.35.88
Feb 06 17:17:24 shd ntpd[819]: Soliciting pool server 23.95.49.216
Feb 06 17:17:24 shd ntpd[819]: Soliciting pool server 2a05:dfc1:3c16:13a9::123
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "network"...
Feb 06 17:17:25 shd volumio[716]: info: Refreshing Cached IP Addresses
Feb 06 17:17:25 shd sudo[974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 06 17:17:25 shd sudo[974]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:25 shd sudo[976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 06 17:17:25 shd sudo[976]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:25 shd sudo[974]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "services"...
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "alsa_controller"...
Feb 06 17:17:25 shd sudo[985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 06 17:17:25 shd sudo[976]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:25 shd sudo[985]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:25 shd sudo[985]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:25 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "wizard"...
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "networkfs"...
Feb 06 17:17:25 shd volumio[716]: info: Starting Udev Watcher for removable devices
Feb 06 17:17:25 shd sudo[1004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=tolik,password=_toli4chek5,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.105/musicvault /mnt/NAS/musicvault
Feb 06 17:17:25 shd sudo[1004]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:25 shd kernel: FS-Cache: Loaded
Feb 06 17:17:25 shd volumio[716]: info: Ignoring mount for partition: BOOT
Feb 06 17:17:25 shd volumio[716]: info: Ignoring mount for partition: volumio
Feb 06 17:17:25 shd volumio[716]: info: Ignoring mount for partition: volumio_data
Feb 06 17:17:25 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "volumio_command_line_client"...
Feb 06 17:17:25 shd volumio[716]: info: Plugin upnp is not enabled
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "my_music"...
Feb 06 17:17:25 shd volumio[716]: info: Loading plugin "mpd"...
Feb 06 17:17:25 shd kernel: FS-Cache: Netfs 'cifs' registered for caching
Feb 06 17:17:25 shd kernel: Key type cifs.spnego registered
Feb 06 17:17:25 shd kernel: Key type cifs.idmap registered
Feb 06 17:17:25 shd kernel: CIFS: Attempting to mount //192.168.1.105/musicvault
Feb 06 17:17:25 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.
Feb 06 17:17:26 shd volumio[716]: info: Plugin upnp_browser is not enabled
Feb 06 17:17:26 shd volumio[716]: info: Plugin bluetooth is not enabled
Feb 06 17:17:26 shd volumio[716]: info: Loading plugin "alarm-clock"...
Feb 06 17:17:26 shd sudo[1004]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.975bc01d does not match aorg 0000000000.00000000 from server@138.68.201.49 xmt 0xed30f507.5868342c
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.974878c6 does not match aorg 0000000000.00000000 from server@50.218.103.254 xmt 0xed30f507.5b36ce46
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.973799da does not match aorg 0000000000.00000000 from server@72.30.35.88 xmt 0xed30f507.5a3c6982
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.97551d28 does not match aorg 0000000000.00000000 from server@23.186.168.126 xmt 0xed30f507.588f2388
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.97626604 does not match aorg 0000000000.00000000 from server@216.66.48.42 xmt 0xed30f507.590505ac
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.975ddc0c does not match aorg 0000000000.00000000 from server@172.233.155.39 xmt 0xed30f507.5ae31600
Feb 06 17:17:27 shd ntpd[819]: receive: Unexpected origin timestamp 0xed30f506.974d49eb does not match aorg 0000000000.00000000 from server@172.235.60.8 xmt 0xed30f507.5b1941e6
Feb 06 17:17:27 shd volumio[716]: info: Loading plugin "manifestui"...
Feb 06 17:17:27 shd volumio[716]: info: Plugin metavolumio is not enabled
Feb 06 17:17:27 shd volumio[716]: info: Plugin airplay_emulation is not enabled
Feb 06 17:17:27 shd volumio[716]: info: Plugin cd_controller is not enabled
Feb 06 17:17:27 shd volumio[716]: info: Loading plugin "last_100"...
Feb 06 17:17:27 shd volumio[716]: info: Loading plugin "qobuzconnect"...
Feb 06 17:17:28 shd volumio[716]: info: Plugin raat is not enabled
Feb 06 17:17:28 shd volumio[716]: info: Loading plugin "streaming_services"...
Feb 06 17:17:30 shd volumio[716]: info: Starting Streaming Service Transparent Proxy
Feb 06 17:17:30 shd volumio[716]: info: Plugin tidalconnect is not enabled
Feb 06 17:17:30 shd volumio[716]: info: Loading plugin "webradio"...
Feb 06 17:17:30 shd volumio[716]: info: Loading plugin "i2s_dacs"...
Feb 06 17:17:30 shd volumio[716]: info: I2S DAC not set, start Auto-detection
Feb 06 17:17:31 shd volumio[716]: info: Loading plugin "volumiodiscovery"...
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 06 17:17:31 shd node[716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** For more information see
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 06 17:17:31 shd volumio[716]: *** WARNING *** For more information see
Feb 06 17:17:31 shd node[716]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 06 17:17:31 shd node[716]: *** WARNING *** For more information see
Feb 06 17:17:31 shd node[716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 06 17:17:31 shd node[716]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 06 17:17:31 shd node[716]: *** WARNING *** For more information see
Feb 06 17:17:31 shd volumio[716]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 06 17:17:31 shd volumio[716]: info: Discovery: Started advertising with name: SHD
Feb 06 17:17:31 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 06 17:17:31 shd volumio[716]: info: Loading plugin "spop"...
Feb 06 17:17:32 shd volumio[716]: STREAMING PROXY: Starting server on port 3245
Feb 06 17:17:32 shd volumio[716]: Node JS runtime: 14
Feb 06 17:17:34 shd volumio[716]: info: Loading plugin "squeezelite_mc"...
Feb 06 17:17:35 shd volumio-remote-updater[519]: [2026-02-06 17:17:35] [connect] Successful connection
Feb 06 17:17:36 shd volumio[716]: info: Plugin multiroom is not enabled
Feb 06 17:17:36 shd volumio[716]: info: Loading plugin "outputs"...
Feb 06 17:17:36 shd volumio[716]: info: Loading plugin "albumart"...
Feb 06 17:17:36 shd systemd[1]: systemd-fsckd.service: Succeeded.
Feb 06 17:17:36 shd volumio[716]: info: Plugin ms_surface_dial is not enabled
Feb 06 17:17:36 shd volumio[716]: info: Plugin example_plugin is not enabled
Feb 06 17:17:36 shd volumio[716]: info: Loading plugin "hi_res_audio"...
Feb 06 17:17:36 shd volumio[716]: Forking 3 albumart workers
Feb 06 17:17:38 shd volumio[716]: Starting albumart workers
Feb 06 17:17:38 shd volumio[716]: Starting albumart workers
Feb 06 17:17:38 shd volumio[716]: Starting albumart workers
Feb 06 17:17:39 shd volumio[716]: info: Applying required configuration parameters for plugin hi_res_audio
Feb 06 17:17:39 shd volumio[716]: info: Loading plugin "inputs"...
Feb 06 17:17:41 shd volumio[716]: info: Loading plugin "qobuz"...
Feb 06 17:17:43 shd volumio[716]: info: Loading plugin "tidal"...
Feb 06 17:17:46 shd volumio[716]: info: Loading plugin "oem_helper"...
Feb 06 17:17:48 shd volumio[716]: info: Applying required configuration parameters for plugin oem_helper
Feb 06 17:17:48 shd volumio[716]: info: Loading plugin "updater_comm"...
Feb 06 17:17:48 shd volumio[716]: info: Plugin mpdemulation is not enabled
Feb 06 17:17:48 shd volumio[716]: info: Loading plugin "rest_api"...
Feb 06 17:17:48 shd volumio[716]: info: Loading plugin "websocket"...
Feb 06 17:17:48 shd volumio[716]: info: Starting Socket.io Server version 2.3.0
Feb 06 17:17:48 shd volumio[716]: info: Loading i18n strings for locale en
Feb 06 17:17:48 shd volumio[716]: Updating browse sources language
Feb 06 17:17:48 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:48 shd systemd[1]: systemd-timedated.service: Succeeded.
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::initPlayerControls
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 06 17:17:49 shd volumio[716]: Express server listening on port 3000
Feb 06 17:17:49 shd volumio[716]: [Metrics] WebUI: 30s 315.68ms
Feb 06 17:17:49 shd volumio[716]: info: CoreStateMachine::resetVolumioState
Feb 06 17:17:49 shd volumio[716]: info: CoreStateMachine::getcurrentVolume
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::volumioRetrievevolume
Feb 06 17:17:49 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:49 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:49 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:49 shd volumio[716]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
Feb 06 17:17:49 shd volumio[716]: info: Completed loading Core Plugins
Feb 06 17:17:49 shd volumio[716]: info: Preparing to generate the ALSA configuration file
Feb 06 17:17:49 shd volumio[716]: info: Volumio Network Manager: Network status updated: 1
Feb 06 17:17:49 shd volumio[716]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Feb 06 17:17:49 shd volumio[716]: wlan0 Interface doesn't support scanning.
Feb 06 17:17:49 shd volumio[716]: info: Cannot use regular scanning, forcing with ap-force
Feb 06 17:17:49 shd sudo[1133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Feb 06 17:17:49 shd sudo[1133]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:49 shd sudo[1133]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:49 shd volumio[716]: command failed: No such device (-19)
Feb 06 17:17:49 shd volumio[716]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
Feb 06 17:17:49 shd volumio[716]: command failed: No such device (-19)
Feb 06 17:17:49 shd volumio[716]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
Feb 06 17:17:49 shd volumio[716]: info: Reloading queue from file
Feb 06 17:17:49 shd volumio[716]: info: Asound.conf file unchanged, so no further update is needed
Feb 06 17:17:49 shd volumio[716]: info: Output device has changed, restarting MPD
Feb 06 17:17:49 shd sudo[1143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 06 17:17:49 shd sudo[1143]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:49 shd volumio[716]: info: ___________ START PLUGINS ___________
Feb 06 17:17:49 shd sudo[1143]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:49 shd volumio[716]: info: ControllerMpd::onStart: Initializing MPD
Feb 06 17:17:49 shd volumio[716]: info: Creating MPD Configuration file
Feb 06 17:17:49 shd sudo[1145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 06 17:17:49 shd sudo[1145]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd sudo[1149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 06 17:17:50 shd sudo[1149]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd systemd[1]: Listening on mpd.socket.
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 06 17:17:50 shd volumio[716]: info: [1770419870023] CoreMusicLibrary::Adding element Last_100
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:50 shd systemd[1]: Starting Music Player Daemon...
Feb 06 17:17:50 shd volumio[716]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Feb 06 17:17:50 shd sudo[1149]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:50 shd sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 06 17:17:50 shd sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM
Feb 06 17:17:50 shd systemd[1]: mpd.service: Succeeded.
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:50 shd volumio[716]: info: QobuzConnect: Starting Qobuz Connect socket and service
Feb 06 17:17:50 shd systemd[1]: Stopped Music Player Daemon.
Feb 06 17:17:50 shd systemd[1]: Starting Music Player Daemon...
Feb 06 17:17:50 shd volumio[716]: info: Streaming services startup
Feb 06 17:17:50 shd volumio[716]: info: Starting Streaming Daemon
Feb 06 17:17:50 shd sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Feb 06 17:17:50 shd sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd sudo[1160]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:50 shd sudo[1163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 06 17:17:50 shd volumio-remote-updater[519]: [2026-02-06 17:17:50] [connect] Successful connection
Feb 06 17:17:50 shd sudo[1163]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Feb 06 17:17:50 shd sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd sudo[1163]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 06 17:17:50 shd volumio[716]: info: [1770419870330] CoreMusicLibrary::Adding element Webradio
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 06 17:17:50 shd sudo[1158]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 06 17:17:50 shd sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:50 shd volumio[716]: info: Initializing BBC Radios
Feb 06 17:17:50 shd sudo[1158]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
Feb 06 17:17:50 shd sudo[1158]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:50 shd systemd[1]: Started Volumio Qobuz Connect Service.
Feb 06 17:17:50 shd sudo[1165]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:50 shd volumio[716]: info: Creating Spotify config file
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:50 shd volumio[716]: info: [squeezelite_mc] Starting proxy server...
Feb 06 17:17:50 shd volumio[716]: error: Hi Res Audio Failed Login: Missing Login Data
Feb 06 17:17:50 shd volumio[716]: info: Adding HIGHRESAUDIO REST API Endpoints
Feb 06 17:17:50 shd volumio[716]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Feb 06 17:17:50 shd volumio[716]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 06 17:17:50 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:51 shd volumio[716]: info: Volumio Calling Home
Feb 06 17:17:51 shd volumio[716]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Proxy server started on port 32941
Feb 06 17:17:51 shd volumio[716]: info: Stopping AccessToken refresher cron for QOBUZ
Feb 06 17:17:51 shd volumio[716]: info: AccessToken refresher cron started for QOBUZ
Feb 06 17:17:51 shd volumio[716]: info: Adding TIDAL REST API Endpoints
Feb 06 17:17:51 shd volumio[716]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal
Feb 06 17:17:51 shd volumio[716]: info: Adding QOBUZ REST API Endpoints
Feb 06 17:17:51 shd volumio[716]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioRetrievevolume
Feb 06 17:17:51 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Server discovery started
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Player finder started
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true
Feb 06 17:17:51 shd volumio[716]: info: Setting Device type: NanoPi NEO 3
Feb 06 17:17:51 shd volumio[716]: info: CoreStateMachine::setRepeat null single undefined
Feb 06 17:17:51 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: CoreStateMachine::setRandom null
Feb 06 17:17:51 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:51 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:51 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:51 shd volumio[716]: info: Serial port opened successfully
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Card 0 supports the following ALSA formats: ["S16_LE","S24_LE"]
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"shd","dsdFormat":"dop","card":"0","mixerType":"None","mixer":null}
Feb 06 17:17:51 shd volumio[716]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 06 17:17:51 shd volumio[716]: error: Cannot start Volumio Streaming Daemon
Feb 06 17:17:51 shd volumio[716]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 06 17:17:51 shd volumio[716]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 06 17:17:51 shd volumio[716]: info: MPD Permissions set
Feb 06 17:17:51 shd volumio[716]: info: MPD Permissions set
Feb 06 17:17:51 shd volumio-remote-updater[519]: [2026-02-06 17:17:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1770419870 101
Feb 06 17:17:51 shd volumio[716]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1
Feb 06 17:17:52 shd sudo[1202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf
Feb 06 17:17:52 shd sudo[1202]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:52 shd sudo[1202]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:52 shd volumio[716]: info: Executing endpoint qc_getconfig
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.350 [1172.1172] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Feb 06 17:17:52 shd volumio[716]: info: [squeezelite_mc] Server discovered: {"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}
Feb 06 17:17:52 shd volumio[716]: info: Volumio called home
Feb 06 17:17:52 shd volumio[716]: info: Spotify config file written
Feb 06 17:17:52 shd volumio[716]: info: Discovery: adding fe055f40-770c-4d91-8fd1-263bc5203033
Feb 06 17:17:52 shd volumio[716]: info: Discovery: Found device SHD
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:52 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:52 shd sudo[1207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 06 17:17:52 shd sudo[1207]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.517 [1172.1172] INFO VolumeManager: [0x152bb60]: Setting new playback volume: 75
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.518 [1172.1172] INFO VolumeManager: [0x152bb60]: Setting new mute state: 0
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.518 [1172.1172] INFO QobuzConnect: [0x152c530]: Client initialized!
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.518 [1172.1172] INFO SampleApp: Starting Avahi advertising, name: SHD, service name: _qobuz-connect._tcp
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.550 [1172.1172] INFO LocalConfigManager: [0x152b440]: Starting Local Configuration server
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.550 [1172.1172] INFO SampleApp: Starting Local configuration server
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.552 [1172.1172] INFO SampleApp: Playback volume changed: 75
Feb 06 17:17:52 shd qobuz-connect[1172]: 20260206 17:17:52.553 [1172.1172] INFO SampleApp: Connected to UNIX socket client 0x1520ed8
Feb 06 17:17:52 shd systemd[1]: Started go-librespot Daemon.
Feb 06 17:17:52 shd go-librespot[1210]: go-librespot daemon starting...
Feb 06 17:17:52 shd sudo[1207]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:52 shd volumio[716]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 06 17:17:52 shd volumio[716]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Feb 06 17:17:52 shd volumio[716]: info: QobuzConnect: QOBUZ Connect daemon connected
Feb 06 17:17:52 shd volumio[716]: info: [squeezelite_mc] Executing alsactl -L -R nrestore
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore
Feb 06 17:17:52 shd sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Feb 06 17:17:52 shd sudo[1215]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 06 17:17:52 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Feb 06 17:17:52 shd go-librespot[1210]: time="2026-02-06T17:17:52-06:00" level=info msg="running go-librespot 0.4.0"
Feb 06 17:17:52 shd go-librespot[1210]: time="2026-02-06T17:17:52-06:00" level=debug msg="app state loaded"
Feb 06 17:17:52 shd go-librespot[1210]: time="2026-02-06T17:17:52-06:00" level=debug msg="stored credentials not found"
Feb 06 17:17:52 shd go-librespot[1210]: time="2026-02-06T17:17:52-06:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:53 shd volumio[716]: info: No need to fix Spotify hosts
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat
Feb 06 17:17:53 shd volumio[716]: info: Adding MINIDSP Inputs
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 06 17:17:53 shd volumio[716]: info: [1770419873024] CoreMusicLibrary::Adding element Inputs
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 06 17:17:53 shd volumio[716]: info: [1770419873035] CoreMusicLibrary::Adding element Presets
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:53 shd volumio[716]: Cannot find translation for source Presets
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:53 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:53 shd volumio[716]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 06 17:17:53 shd volumio[716]: info: An error occurred while refreshing Spotify Token Error: Bad Request
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::volumiosetSourceActiveno-source
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 06 17:17:53 shd volumio[716]: Cannot find translation for source Presets
Feb 06 17:17:53 shd sudo[1236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service
Feb 06 17:17:53 shd sudo[1236]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:53 shd sudo[1236]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:53 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:53 shd volumio[716]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 06 17:17:53 shd go-librespot[1210]: time="2026-02-06T17:17:53-06: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 06 17:17:53 shd go-librespot[1210]: time="2026-02-06T17:17:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 06 17:17:53 shd go-librespot[1210]: time="2026-02-06T17:17:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 06 17:17:53 shd go-librespot[1210]: time="2026-02-06T17:17:53-06:00" level=info msg="zeroconf server listening on port 34297"
Feb 06 17:17:53 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume
Feb 06 17:17:53 shd volumio[716]: info: Enabling external Volume Control
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:53 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 06 17:17:53 shd sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Feb 06 17:17:53 shd sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:53 shd systemd[1]: Reloading.
Feb 06 17:17:54 shd volumio[716]: info: [squeezelite_mc] Notification listener started
Feb 06 17:17:54 shd volumio[716]: info: [squeezelite_mc] Getting players connected to Centre (192.168.1.105)
Feb 06 17:17:54 shd systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
Feb 06 17:17:54 shd volumio[716]: info: [squeezelite_mc] Players connected to Centre (192.168.1.105): [{"id":"00:04:20:10:04:24","uuid":null,"ip":"172.17.0.1","name":"Transporter","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}},{"id":"00:04:20:05:b4:19","uuid":null,"ip":"172.17.0.1","name":"Squeeze2","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}},{"id":"00:04:20:22:e4:4a","uuid":"50b51a5808bac2fc2275609905a3cbad","ip":"172.17.0.1","name":"Squeezebox Touch","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}}]
Feb 06 17:17:54 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:54 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:54 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 06 17:17:54 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:54 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:54 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:54 shd systemd[1]: serial-getty@ttyS2.service: Current command vanished from the unit file, execution of the command list won't be resumed.
Feb 06 17:17:55 shd systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed.
Feb 06 17:17:55 shd sudo[1239]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:55 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:55 shd sudo[1256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:55 shd sudo[1256]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:55 shd sudo[1256]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:55 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true
Feb 06 17:17:55 shd sudo[1259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite
Feb 06 17:17:55 shd sudo[1259]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:55 shd systemd[1]: Starting Squeezelite lightweight headless Squeezebox emulator...
Feb 06 17:17:55 shd systemd[1]: Started Squeezelite lightweight headless Squeezebox emulator.
Feb 06 17:17:55 shd sudo[1259]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:55 shd volumio[716]: info: CoreStateMachine::pushState
Feb 06 17:17:55 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:55 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 06 17:17:55 shd volumio[716]: info: CoreCommandRouter::volumioPushState
Feb 06 17:17:55 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:17:55 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:17:55 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume
Feb 06 17:17:56 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:56 shd sudo[1280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:56 shd sudo[1280]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:56 shd sudo[1280]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:56 shd volumio[716]: info: go-librespot daemon successfully initialized
Feb 06 17:17:56 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:56 shd sudo[1283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:56 shd sudo[1283]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:56 shd sudo[1283]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:57 shd mpd[1174]: Feb 06 17:17 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 06 17:17:57 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:57 shd sudo[1286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:57 shd sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:57 shd sudo[1286]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:58 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:58 shd systemd[1]: Started Music Player Daemon.
Feb 06 17:17:58 shd sudo[1151]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:58 shd sudo[1289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:58 shd sudo[1145]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:58 shd sudo[1289]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:58 shd sudo[1289]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:58 shd volumio[716]: error: MPD error: The expression evaluated to a falsy value:
Feb 06 17:17:58 shd volumio[716]: assert.ok(self.idling)
Feb 06 17:17:58 shd volumio[716]: error: The expression evaluated to a falsy value:
Feb 06 17:17:58 shd volumio[716]: assert.ok(self.idling)
Feb 06 17:17:58 shd volumio[716]: info: MPD running with PID1174
Feb 06 17:17:58 shd volumio[716]: ,establishing connection
Feb 06 17:17:58 shd volumio[716]: error: updateQueue error: null
Feb 06 17:17:58 shd volumio[716]: error: updateQueue error: null
Feb 06 17:17:58 shd go-librespot[1210]: time="2026-02-06T17:17:58-06:00" level=debug msg="obtained new client token: AADXOV2z/Vxvx/t+RQEmrhxpHrtLuCl4AKVdKG+zrDsgZm55HVYyi14UZsf34s0wVzacCaR/r1ehIWwc/80C3k9oqv+8jLBpESNCn8uFEtr+eHqcyZpc4NpXsOeqvfUrvbYIzhPzlt/AJjjivX+OqvLA8+jKETqTvnY365GdR3UuodLTh6Dz9epR+0lcpVBCc3d+HURx5Hl4vRLI+3b2rmrrXBmQU0bM5bo3kzRnOYU/UEzNuj2/SP6Z"
Feb 06 17:17:58 shd volumio[716]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true
Feb 06 17:17:58 shd sudo[1296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite
Feb 06 17:17:58 shd sudo[1296]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:17:58 shd sudo[1296]: pam_unix(sudo:session): session closed for user root
Feb 06 17:17:58 shd volumio[716]: info: Completed starting Core Plugins
Feb 06 17:17:58 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:58 shd volumio[716]: info: ----- MyVolumio plugins startup ----
Feb 06 17:17:58 shd volumio[716]: info: -------------------------------------------
Feb 06 17:17:58 shd volumio[716]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 06 17:17:58 shd go-librespot[1210]: time="2026-02-06T17:17:58-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070"
Feb 06 17:17:58 shd go-librespot[1210]: time="2026-02-06T17:17:58-06:00" level=debug msg="completed keyexchange"
Feb 06 17:17:58 shd go-librespot[1210]: time="2026-02-06T17:17:58-06:00" level=debug msg="completed challenge"
Feb 06 17:17:58 shd go-librespot[1210]: time="2026-02-06T17:17:58-06:00" level=info msg="authenticated AP" username="to***k5"
Feb 06 17:17:59 shd volumio[716]: info: Initializing connection to go-librespot Websocket
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="new websocket client"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=info msg="authenticated Login5" username="to***k5"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=info msg="accepted zeroconf from iPad" username="to***k5"
Feb 06 17:17:59 shd volumio[716]: info: Connection to go-librespot Websocket established
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="dealer connection opened"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=trace msg="starting accesspoint recv loop"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=trace msg="starting dealer recv loop"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="received connection id: NWZjYTI4NTYtMTA4...RDU1RkFDQ0VGRg=="
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=trace msg="received accesspoint ping"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="put connect state because NEW_DEVICE"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="update volume requested to 53083/65535"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=trace msg="received accesspoint pong ack"
Feb 06 17:17:59 shd go-librespot[1210]: time="2026-02-06T17:17:59-06:00" level=debug msg="handling transfer player command from 4ef713b424f047e29f320004036ab01de62f8393"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="resolved context of track" uri="spotify:album:6jOgGVWcRqthnChiKSDQ0B"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=trace msg="fetched new page 0 with 6 items (list: 6)" uri="spotify:album:6jOgGVWcRqthnChiKSDQ0B"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="loading track (paused: false, position: 272834ms)" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=trace msg="emitting websocket event: will_play"
Feb 06 17:18:00 shd volumio[716]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:6jOgGVWcRqthnChiKSDQ0B","uri":"spotify:track:2WKENkQemR447m46nAJ5KH","play_origin":"album"}}
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1104"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="selected format OGG_VORBIS_320 (eefaf7e156c3d17089714396abe973e08388e947)" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="requested aes key for file eefaf7e156c3d17089714396abe973e08388e947, gid: 2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="fetched first chunk of 37, total size is 19368708 bytes" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:00 shd volumio[716]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP
Feb 06 17:18:00 shd go-librespot[1210]: time="2026-02-06T17:18:00-06:00" level=debug msg="fetched chunk 1/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 24/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 22/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="seek to 272834ms (diff: 215ms, samples: 12031979, bytes: 11755826)" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="created new output device"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 3/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 23/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd volumio[716]: info: [squeezelite_mc] 'client' notification received from Centre (192.168.1.105); type is 'connect'
Feb 06 17:18:01 shd volumio[716]: info: [squeezelite_mc] Getting players connected to Centre (192.168.1.105)
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06: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"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=info msg="loaded track \"The Peacock\" (paused: false, position: 272834ms, duration: 453280ms, prefetched: false)" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 06 17:18:01 shd sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 25/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="fetched chunk 2/36, size: 524288" uri="spotify:track:2WKENkQemR447m46nAJ5KH"
Feb 06 17:18:01 shd sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Feb 06 17:18:01 shd sudo[1305]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 06 17:18:01 shd systemd[1]: Started MPD Monitor Service.
Feb 06 17:18:01 shd sudo[1302]: pam_unix(sudo:session): session closed for user root
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="scheduling prefetch in 150s"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="emitting websocket event: metadata"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="emitting websocket event: active"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="sending successful reply for dealer request"
Feb 06 17:18:01 shd volumio[716]: info: Successfully started MPD Monitor
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Feb 06 17:18:01 shd volumio[716]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2WKENkQemR447m46nAJ5KH","name":"The Peacock","artist_names":["Ole Lukkoye"],"album_name":"Horse-Tiger","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c145c358a7ad03cd8318817d","position":272834,"duration":453280,"release_date":"year:2000","track_number":5,"disc_number":1}}
Feb 06 17:18:01 shd volumio[716]: SPOTIFY: received: {"type":"active","data":null}
Feb 06 17:18:01 shd mpd_monitor.sh[1306]: MPD Monitor Service: Starting MPD Monitor Service
Feb 06 17:18:01 shd volumio[716]: info: Aligning Spotify Volume to Volumio Volume
Feb 06 17:18:01 shd volumio[716]: info: CoreCommandRouter::volumioGetState
Feb 06 17:18:01 shd volumio[716]: info: CorePlayQueue::getTrack 0
Feb 06 17:18:01 shd volumio[716]: info: Setting Spotify Volume from Volumio: 81
Feb 06 17:18:01 shd systemd[1]: Stopping MPD Monitor Service...
Feb 06 17:18:01 shd systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM
Feb 06 17:18:01 shd systemd[1]: mpd_monitor.service: Succeeded.
Feb 06 17:18:01 shd systemd[1]: Stopped MPD Monitor Service.
Feb 06 17:18:01 shd volumio[716]: info: [squeezelite_mc] Players connected to Centre (192.168.1.105): [{"id":"00:04:20:05:b4:19","uuid":null,"ip":"172.17.0.1","name":"Squeeze2","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}},{"id":"00:04:20:22:e4:4a","uuid":"50b51a5808bac2fc2275609905a3cbad","ip":"172.17.0.1","name":"Squeezebox Touch","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}},{"id":"86:48:db:b2:e3:44","uuid":null,"ip":"172.17.0.1","name":"shd","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}},{"id":"00:04:20:10:04:24","uuid":null,"ip":"172.17.0.1","name":"Transporter","server":{"ip":"192.168.1.105","name":"Centre","ver":"9.0.3","uuid":"5bce1aed-6b94-4465-8c05-d43fa7439701","jsonPort":"9000","cliPort":"9090"}}]
Feb 06 17:18:01 shd systemd[1]: Started MPD Monitor Service.
Feb 06 17:18:01 shd sudo[1305]: pam_unix(sudo:session): session closed for user root
Feb 06 17:18:01 shd mpd_monitor.sh[1309]: MPD Monitor Service: Starting MPD Monitor Service
Feb 06 17:18:01 shd volumio[716]: info: Successfully started MPD Monitor
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="put connect state because VOLUME_CHANGED"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="emitting websocket event: volume"
Feb 06 17:18:01 shd volumio[716]: SPOTIFY: received: {"type":"volume","data":{"value":81,"max":100}}
Feb 06 17:18:01 shd volumio[716]: SPOTIFY: RECEIVED SPOTIFY VOLUME 81
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 06 17:18:01 shd go-librespot[1210]: time="2026-02-06T17:18:01-06:00" level=trace msg="emitting websocket event: playing"
Feb 06 17:18:01 shd volumio[716]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:6jOgGVWcRqthnChiKSDQ0B","uri":"spotify:track:2WKENkQemR447m46nAJ5KH","resume":false,"play_origin":"album"}}
Feb 06 17:18:01 shd volumio[716]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 06 17:18:01 shd volumio[716]: TypeError: Cannot read property 'service' of undefined
Feb 06 17:18:01 shd volumio[716]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50)
Feb 06 17:18:01 shd volumio[716]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18)
Feb 06 17:18:01 shd volumio[716]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14)
Feb 06 17:18:01 shd volumio[716]: at WebSocket.emit (events.js:400:28)
Feb 06 17:18:01 shd volumio[716]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20)
Feb 06 17:18:01 shd volumio[716]: at Receiver.emit (events.js:400:28)
Feb 06 17:18:01 shd volumio[716]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14)
Feb 06 17:18:01 shd volumio[716]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10)
Feb 06 17:18:01 shd volumio[716]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16)
Feb 06 17:18:01 shd volumio[716]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10)
Feb 06 17:18:01 shd volumio[716]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 06 17:18:02 shd sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-06 17:17
Feb 06 17:18:02 shd sudo[1322]: 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"