-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2025-12-19 16:03:40 CET. -- Dec 19 16:02:51 tycshd systemd-timedated[941]: Changed local time to Fri Dec 19 16:02:51 2025 Dec 19 16:02:51 tycshd systemd[1]: Starting Daily apt download activities... Dec 19 16:02:51 tycshd sudo[939]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:51 tycshd volumio-time-update[511]: volumio-time-update-util: System time updated successfully. Dec 19 16:02:51 tycshd systemd[1]: Started Volumio Time Update Utility. Dec 19 16:02:51 tycshd volumio[712]: info: Starting Streaming Service Transparent Proxy Dec 19 16:02:51 tycshd volumio[712]: info: Plugin tidalconnect is not enabled Dec 19 16:02:51 tycshd volumio[712]: info: Loading plugin "webradio"... Dec 19 16:02:51 tycshd systemd[1]: Started Samba NMB Daemon. Dec 19 16:02:51 tycshd nmbd[667]: [2025/12/19 16:02:51.558666, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 19 16:02:51 tycshd nmbd[667]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 19 16:02:51 tycshd systemd[1]: Starting Samba Winbind Daemon... Dec 19 16:02:51 tycshd volumio[712]: info: Loading plugin "i2s_dacs"... Dec 19 16:02:51 tycshd volumio[712]: info: I2S DAC not set, start Auto-detection Dec 19 16:02:51 tycshd volumio[712]: info: Loading plugin "volumiodiscovery"... Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** For more information see Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 16:02:51 tycshd node[712]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 19 16:02:51 tycshd volumio[712]: *** WARNING *** For more information see Dec 19 16:02:51 tycshd node[712]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 16:02:51 tycshd node[712]: *** WARNING *** For more information see Dec 19 16:02:51 tycshd node[712]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 19 16:02:51 tycshd node[712]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 16:02:51 tycshd node[712]: *** WARNING *** For more information see Dec 19 16:02:51 tycshd volumio[712]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 19 16:02:51 tycshd volumio[712]: info: Discovery: Started advertising with name: TycSHD Dec 19 16:02:51 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 19 16:02:51 tycshd volumio[712]: info: Loading plugin "soundcloud"... Dec 19 16:02:52 tycshd winbindd[968]: [2025/12/19 16:02:52.087032, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 19 16:02:52 tycshd winbindd[968]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 19 16:02:52 tycshd systemd[1]: Started Samba Winbind Daemon. Dec 19 16:02:52 tycshd systemd[1]: Starting Samba SMB Daemon... Dec 19 16:02:52 tycshd winbindd[968]: [2025/12/19 16:02:52.127029, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 19 16:02:52 tycshd winbindd[968]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 19 16:02:52 tycshd systemd[1]: apt-daily.service: Succeeded. Dec 19 16:02:52 tycshd systemd[1]: Started Daily apt download activities. Dec 19 16:02:52 tycshd systemd[1]: Starting Daily apt upgrade and clean activities... Dec 19 16:02:52 tycshd volumio[712]: info: Loading plugin "spop"... Dec 19 16:02:52 tycshd volumio-remote-updater[484]: [2025-12-19 16:02:52] [connect] Successful connection Dec 19 16:02:53 tycshd systemd[1]: Started Samba SMB Daemon. Dec 19 16:02:53 tycshd systemd[1]: Reached target Multi-User System. Dec 19 16:02:53 tycshd systemd[1]: Reached target Graphical Interface. Dec 19 16:02:53 tycshd smbd[1004]: [2025/12/19 16:02:53.121536, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 19 16:02:53 tycshd systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 19 16:02:53 tycshd smbd[1004]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 19 16:02:53 tycshd systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 19 16:02:53 tycshd systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 19 16:02:53 tycshd volumio[712]: STREAMING PROXY: Starting server on port 3245 Dec 19 16:02:53 tycshd volumio[712]: Node JS runtime: 14 Dec 19 16:02:53 tycshd systemd[1]: apt-daily-upgrade.service: Succeeded. Dec 19 16:02:53 tycshd systemd[1]: Started Daily apt upgrade and clean activities. Dec 19 16:02:53 tycshd systemd[1]: Startup finished in 6.701s (kernel) + 21.870s (userspace) = 28.572s. Dec 19 16:02:54 tycshd volumio[712]: info: Loading plugin "youtube2"... Dec 19 16:02:56 tycshd volumio[712]: info: Loading plugin "multiroom"... Dec 19 16:02:59 tycshd volumio[712]: info: Applying required configuration parameters for plugin multiroom Dec 19 16:02:59 tycshd sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 19 16:02:59 tycshd sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:02:59 tycshd sudo[1077]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:59 tycshd volumio[712]: info: MRS: MultiRoom plugin initialized Dec 19 16:02:59 tycshd volumio[712]: info: MRS: STOPPING SNAPCLIENT Dec 19 16:02:59 tycshd volumio[712]: info: MRS: Snap server stop Dec 19 16:02:59 tycshd sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 19 16:02:59 tycshd sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:02:59 tycshd volumio[712]: info: MRS: STOPPING volumioStreaming Dec 19 16:02:59 tycshd sudo[1096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 19 16:02:59 tycshd sudo[1096]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:02:59 tycshd sudo[1098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 19 16:02:59 tycshd sudo[1098]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:02:59 tycshd volumio[712]: info: Loading plugin "outputs"... Dec 19 16:02:59 tycshd sudo[1093]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:59 tycshd sudo[1101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 19 16:02:59 tycshd sudo[1101]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:02:59 tycshd sudo[1101]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:59 tycshd volumio[712]: info: Loading plugin "albumart"... Dec 19 16:02:59 tycshd volumio[712]: info: Plugin ms_surface_dial is not enabled Dec 19 16:02:59 tycshd volumio[712]: info: Plugin example_plugin is not enabled Dec 19 16:02:59 tycshd sudo[1098]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:59 tycshd sudo[1096]: pam_unix(sudo:session): session closed for user root Dec 19 16:02:59 tycshd volumio[712]: info: Loading plugin "hi_res_audio"... Dec 19 16:02:59 tycshd volumio[712]: Forking 3 albumart workers Dec 19 16:03:01 tycshd volumio[712]: Starting albumart workers Dec 19 16:03:01 tycshd volumio[712]: Starting albumart workers Dec 19 16:03:01 tycshd volumio[712]: Starting albumart workers Dec 19 16:03:01 tycshd volumio[712]: info: Applying required configuration parameters for plugin hi_res_audio Dec 19 16:03:01 tycshd volumio[712]: info: Loading plugin "inputs"... Dec 19 16:03:02 tycshd volumio[712]: info: Loading plugin "qobuz"... Dec 19 16:03:03 tycshd systemd[1]: systemd-fsckd.service: Succeeded. Dec 19 16:03:04 tycshd volumio[712]: info: Loading plugin "tidal"... Dec 19 16:03:06 tycshd volumio[712]: info: Loading plugin "oem_helper"... Dec 19 16:03:07 tycshd volumio-remote-updater[484]: [2025-12-19 16:03:07] [connect] Successful connection Dec 19 16:03:08 tycshd volumio[712]: info: Applying required configuration parameters for plugin oem_helper Dec 19 16:03:08 tycshd volumio[712]: info: Loading plugin "updater_comm"... Dec 19 16:03:08 tycshd volumio[712]: info: Plugin mpdemulation is not enabled Dec 19 16:03:08 tycshd volumio[712]: info: Loading plugin "rest_api"... Dec 19 16:03:08 tycshd volumio[712]: info: Loading plugin "websocket"... Dec 19 16:03:08 tycshd volumio[712]: info: Starting Socket.io Server version 2.3.0 Dec 19 16:03:08 tycshd volumio[712]: info: Loading i18n strings for locale en Dec 19 16:03:08 tycshd volumio[712]: Updating browse sources language Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::initPlayerControls Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 16:03:08 tycshd volumio[712]: Express server listening on port 3000 Dec 19 16:03:08 tycshd volumio[712]: [Metrics] WebUI: 28s 605.20ms Dec 19 16:03:08 tycshd volumio[712]: info: CoreStateMachine::resetVolumioState Dec 19 16:03:08 tycshd volumio[712]: info: CoreStateMachine::getcurrentVolume Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::volumioRetrievevolume Dec 19 16:03:08 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:08 tycshd volumio[712]: info: CorePlayQueue::getTrack 0 Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:08 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:08 tycshd sudo[1175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 19 16:03:08 tycshd sudo[1175]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:08 tycshd sudo[1175]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:08 tycshd sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 19 16:03:08 tycshd sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:08 tycshd volumio[712]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Dec 19 16:03:08 tycshd volumio[712]: info: Completed loading Core Plugins Dec 19 16:03:08 tycshd volumio[712]: info: Preparing to generate the ALSA configuration file Dec 19 16:03:08 tycshd sudo[1178]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd volumio[712]: info: Volumio Network Manager: Network status updated: 0 Dec 19 16:03:09 tycshd volumio[712]: info: MRS: Removed streaming files Dec 19 16:03:09 tycshd volumio[712]: info: MRS: volumioStreaming STOPPED Dec 19 16:03:09 tycshd volumio[712]: info: MRS: SNAPSERVER STOPPED Dec 19 16:03:09 tycshd volumio[712]: info: MRS: SNAPCLIENT STOPPED Dec 19 16:03:09 tycshd volumio[712]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Dec 19 16:03:09 tycshd volumio[712]: wlan0 Interface doesn't support scanning. Dec 19 16:03:09 tycshd volumio[712]: info: Cannot use regular scanning, forcing with ap-force Dec 19 16:03:09 tycshd sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Dec 19 16:03:09 tycshd sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1183]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd volumio[712]: command failed: No such device (-19) Dec 19 16:03:09 tycshd volumio[712]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Dec 19 16:03:09 tycshd volumio[712]: command failed: No such device (-19) Dec 19 16:03:09 tycshd volumio[712]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 19 16:03:09 tycshd volumio[712]: info: Reading ALSA contributions from plugins. Dec 19 16:03:09 tycshd volumio-remote-updater[484]: [2025-12-19 16:03:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1766156587 101 Dec 19 16:03:09 tycshd volumio[712]: 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 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 16:03:09 tycshd volumio[712]: info: Setting Device type: NanoPi NEO 2 Dec 19 16:03:09 tycshd volumio[712]: info: CoreStateMachine::setRepeat undefined single undefined Dec 19 16:03:09 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:09 tycshd volumio[712]: info: CorePlayQueue::getTrack 0 Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:09 tycshd volumio[712]: info: CoreStateMachine::setRandom true Dec 19 16:03:09 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:09 tycshd volumio[712]: info: CorePlayQueue::getTrack 0 Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:09 tycshd volumio[712]: info: Asound.conf file unchanged, so no further update is needed Dec 19 16:03:09 tycshd volumio[712]: info: Output device has changed, restarting MPD Dec 19 16:03:09 tycshd sudo[1193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 19 16:03:09 tycshd sudo[1193]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd systemd[1]: Started UPnP Renderer front-end to MPD. Dec 19 16:03:09 tycshd sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 19 16:03:09 tycshd sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1196]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd volumio[712]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:09 tycshd sudo[1193]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd sudo[1200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 19 16:03:09 tycshd sudo[1200]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd volumio[712]: info: ___________ START PLUGINS ___________ Dec 19 16:03:09 tycshd volumio[712]: info: ControllerMpd::onStart: Initializing MPD Dec 19 16:03:09 tycshd volumio[712]: info: Creating MPD Configuration file Dec 19 16:03:09 tycshd systemd[1]: Listening on mpd.socket. Dec 19 16:03:09 tycshd systemd[1]: Starting Music Player Daemon... Dec 19 16:03:09 tycshd sudo[1207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 19 16:03:09 tycshd sudo[1207]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1207]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:09 tycshd volumio[712]: info: [1766156589783] CoreMusicLibrary::Adding element Media Servers Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:09 tycshd sudo[1212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 19 16:03:09 tycshd sudo[1212]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd volumio[712]: info: Adding METAVOLUMIO REST API Endpoints Dec 19 16:03:09 tycshd volumio[712]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 19 16:03:09 tycshd volumio[712]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 19 16:03:09 tycshd volumio[712]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 19 16:03:09 tycshd volumio[712]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:09 tycshd volumio[712]: info: [1766156589828] CoreMusicLibrary::Adding element Last_100 Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:09 tycshd sudo[1205]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 19 16:03:09 tycshd volumio[712]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 19 16:03:09 tycshd sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1205]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Dec 19 16:03:09 tycshd systemd[1]: mpd.service: Succeeded. Dec 19 16:03:09 tycshd systemd[1]: Stopped Music Player Daemon. Dec 19 16:03:09 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:09 tycshd systemd[1]: Starting Music Player Daemon... Dec 19 16:03:09 tycshd volumio[712]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 19 16:03:09 tycshd volumio[712]: info: Streaming services startup Dec 19 16:03:09 tycshd volumio[712]: info: Starting Streaming Daemon Dec 19 16:03:09 tycshd sudo[1219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 19 16:03:09 tycshd sudo[1219]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1219]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:09 tycshd sudo[1222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 19 16:03:09 tycshd sudo[1222]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 19 16:03:09 tycshd sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:09 tycshd sudo[1222]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:10 tycshd volumio[712]: info: [1766156590013] CoreMusicLibrary::Adding element Webradio Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 16:03:10 tycshd sudo[1217]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 19 16:03:10 tycshd sudo[1217]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:10 tycshd volumio[712]: info: Initializing BBC Radios Dec 19 16:03:10 tycshd sudo[1217]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 19 16:03:10 tycshd sudo[1217]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:10 tycshd systemd[1]: Started Volumio Qobuz Connect Service. Dec 19 16:03:10 tycshd sudo[1223]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:10 tycshd volumio[712]: info: [1766156590171] CoreMusicLibrary::Adding element SoundCloud Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:10 tycshd volumio[712]: Cannot find translation for source SoundCloud Dec 19 16:03:10 tycshd volumio[712]: info: Creating Spotify config file Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:10 tycshd volumio[712]: info: [1766156590340] CoreMusicLibrary::Adding element YouTube2 Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:10 tycshd volumio[712]: Cannot find translation for source SoundCloud Dec 19 16:03:10 tycshd volumio[712]: Cannot find translation for source YouTube2 Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 19 16:03:10 tycshd volumio[712]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:10 tycshd volumio[712]: error: Hi Res Audio Failed Login: Missing Login Data Dec 19 16:03:10 tycshd volumio[712]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 19 16:03:10 tycshd volumio[712]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 19 16:03:10 tycshd volumio[712]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 16:03:10 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:10 tycshd volumio[712]: info: Volumio Calling Home Dec 19 16:03:10 tycshd volumio[712]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 19 16:03:10 tycshd volumio[712]: info: Stopping AccessToken refresher cron for QOBUZ Dec 19 16:03:10 tycshd volumio[712]: info: AccessToken refresher cron started for QOBUZ Dec 19 16:03:10 tycshd volumio[712]: info: Adding TIDAL REST API Endpoints Dec 19 16:03:10 tycshd volumio[712]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Dec 19 16:03:10 tycshd volumio[712]: info: Adding QOBUZ REST API Endpoints Dec 19 16:03:10 tycshd volumio[712]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Dec 19 16:03:10 tycshd volumio[712]: info: Serial port opened successfully Dec 19 16:03:10 tycshd volumio[712]: error: Cannot start Volumio Streaming Daemon Dec 19 16:03:10 tycshd volumio[712]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 19 16:03:10 tycshd volumio[712]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 19 16:03:10 tycshd volumio[712]: info: MPD Permissions set Dec 19 16:03:10 tycshd volumio[712]: info: MPD Permissions set Dec 19 16:03:10 tycshd volumio[712]: info: Upmpdcli Daemon Started Dec 19 16:03:11 tycshd volumio[712]: info: Executing endpoint qc_getconfig Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.079 [1231.1231] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 19 16:03:11 tycshd volumio[712]: info: Spotify config file written Dec 19 16:03:11 tycshd volumio[712]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 19 16:03:11 tycshd sudo[1264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 19 16:03:11 tycshd sudo[1264]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:11 tycshd volumio[712]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 19 16:03:11 tycshd systemd[1]: Started go-librespot Daemon. Dec 19 16:03:11 tycshd sudo[1264]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:11 tycshd go-librespot[1271]: go-librespot daemon starting... Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:11 tycshd volumio[712]: info: No need to fix Spotify hosts Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Dec 19 16:03:11 tycshd volumio[712]: info: Adding MINIDSP Inputs Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:11 tycshd volumio[712]: info: [1766156591373] CoreMusicLibrary::Adding element Inputs Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source SoundCloud Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source YouTube2 Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 16:03:11 tycshd volumio[712]: info: [1766156591379] CoreMusicLibrary::Adding element Presets Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source SoundCloud Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source YouTube2 Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source Presets Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.420 [1231.1231] INFO VolumeManager: [0x1673830]: Setting new playback volume: 75 Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.421 [1231.1231] INFO VolumeManager: [0x1673830]: Setting new mute state: 0 Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.421 [1231.1231] INFO QobuzConnect: [0x1674200]: Client initialized! Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.421 [1231.1231] INFO SampleApp: Starting Avahi advertising, name: TycSHD, service name: _qobuz-connect._tcp Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.432 [1231.1231] INFO LocalConfigManager: [0x1673110]: Starting Local Configuration server Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.432 [1231.1231] INFO SampleApp: Starting Local configuration server Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.432 [1231.1231] INFO SampleApp: Playback volume changed: 75 Dec 19 16:03:11 tycshd qobuz-connect[1231]: 20251219 16:03:11.433 [1231.1231] INFO SampleApp: Connected to UNIX socket client 0x1668ed8 Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:11 tycshd volumio[712]: info: CorePlayQueue::getTrack 0 Dec 19 16:03:11 tycshd volumio[712]: info: CorePlayQueue::getTrack 0 Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::volumiosetSourceActiveno-source Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source SoundCloud Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source YouTube2 Dec 19 16:03:11 tycshd volumio[712]: Cannot find translation for source Presets Dec 19 16:03:11 tycshd volumio[712]: info: CoreCommandRouter::volumioStop Dec 19 16:03:11 tycshd volumio[712]: info: CoreStateMachine::stop Dec 19 16:03:11 tycshd volumio[712]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 19 16:03:11 tycshd volumio[712]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"TOSLINK","disableUiControls":true,"albumart":"/albumart"} Dec 19 16:03:11 tycshd volumio[712]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 19 16:03:11 tycshd go-librespot[1271]: time="2025-12-19T16:03:11+01:00" level=info msg="running go-librespot 0.4.0" Dec 19 16:03:11 tycshd go-librespot[1271]: time="2025-12-19T16:03:11+01:00" level=debug msg="app state loaded" Dec 19 16:03:11 tycshd go-librespot[1271]: time="2025-12-19T16:03:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 19 16:03:12 tycshd volumio[712]: info: CoreCommandRouter::servicePushState Dec 19 16:03:12 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:12 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:12 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:12 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:13 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 19 16:03:13 tycshd volumio[712]: info: Enabling external Volume Control Dec 19 16:03:13 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:13 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:13 tycshd mpd[1234]: Dec 19 16:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 19 16:03:13 tycshd systemd[1]: Started Music Player Daemon. Dec 19 16:03:13 tycshd volumio[712]: Upnp client error: Error: This socket has been ended by the other party Dec 19 16:03:13 tycshd sudo[1200]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:13 tycshd sudo[1212]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:13 tycshd volumio[712]: info: Completed starting Core Plugins Dec 19 16:03:13 tycshd volumio[712]: info: ------------------------------------------- Dec 19 16:03:13 tycshd volumio[712]: info: ----- MyVolumio plugins startup ---- Dec 19 16:03:13 tycshd volumio[712]: info: ------------------------------------------- Dec 19 16:03:13 tycshd volumio[712]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 19 16:03:14 tycshd volumio[712]: info: MPD running with PID1234 Dec 19 16:03:14 tycshd volumio[712]: ,establishing connection Dec 19 16:03:14 tycshd volumio[712]: error: MPD error: The expression evaluated to a falsy value: Dec 19 16:03:14 tycshd volumio[712]: assert.ok(self.idling) Dec 19 16:03:14 tycshd volumio[712]: error: The expression evaluated to a falsy value: Dec 19 16:03:14 tycshd volumio[712]: assert.ok(self.idling) Dec 19 16:03:14 tycshd volumio[712]: error: MPD error: The expression evaluated to a falsy value: Dec 19 16:03:14 tycshd volumio[712]: assert.ok(self.idling) Dec 19 16:03:14 tycshd volumio[712]: error: The expression evaluated to a falsy value: Dec 19 16:03:14 tycshd volumio[712]: assert.ok(self.idling) Dec 19 16:03:14 tycshd volumio[712]: error: updateQueue error: null Dec 19 16:03:14 tycshd volumio[1197]: Generating RSA private key, 4096 bit long modulus (2 primes) Dec 19 16:03:14 tycshd volumio[712]: info: go-librespot daemon successfully initialized Dec 19 16:03:14 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:14 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:14 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:14 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:15 tycshd volumio[712]: info: Volumio Network Manager: Network status updated: 1 Dec 19 16:03:15 tycshd volumio[712]: info: MRS: Getting audio outputs on start Dec 19 16:03:15 tycshd volumio[712]: info: MRS: Requesting all other devices output Dec 19 16:03:15 tycshd volumio[712]: info: CoreStateMachine::pushState Dec 19 16:03:15 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 16:03:15 tycshd volumio[712]: info: CoreCommandRouter::volumioPushState Dec 19 16:03:15 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:15 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Dec 19 16:03:16 tycshd sudo[1323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 19 16:03:16 tycshd sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:17 tycshd sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 19 16:03:17 tycshd sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:17 tycshd systemd[1]: Started MPD Monitor Service. Dec 19 16:03:17 tycshd mpd_monitor.sh[1328]: MPD Monitor Service: Starting MPD Monitor Service Dec 19 16:03:17 tycshd sudo[1323]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:17 tycshd volumio[712]: info: Successfully started MPD Monitor Dec 19 16:03:17 tycshd systemd[1]: Stopping MPD Monitor Service... Dec 19 16:03:17 tycshd systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 19 16:03:17 tycshd systemd[1]: mpd_monitor.service: Succeeded. Dec 19 16:03:17 tycshd systemd[1]: Stopped MPD Monitor Service. Dec 19 16:03:17 tycshd systemd[1]: Started MPD Monitor Service. Dec 19 16:03:17 tycshd sudo[1326]: pam_unix(sudo:session): session closed for user root Dec 19 16:03:17 tycshd volumio[712]: info: Successfully started MPD Monitor Dec 19 16:03:17 tycshd mpd_monitor.sh[1331]: MPD Monitor Service: Starting MPD Monitor Service Dec 19 16:03:17 tycshd volumio[712]: info: Initializing connection to go-librespot Websocket Dec 19 16:03:19 tycshd volumio[712]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 19 16:03:19 tycshd volumio[712]: Cannot compose Albumart path Dec 19 16:03:19 tycshd volumio[712]: Cannot compose Albumart path Dec 19 16:03:20 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Dec 19 16:03:20 tycshd volumio[1197]: ..................................................................++++ Dec 19 16:03:21 tycshd systemd[1]: systemd-timedated.service: Succeeded. Dec 19 16:03:27 tycshd volumio[1197]: ..........................................................................++++ Dec 19 16:03:27 tycshd volumio[1197]: e is 65537 (0x010001) Dec 19 16:03:27 tycshd volumio[1197]: writing RSA key Dec 19 16:03:34 tycshd volumio[712]: error: MyVolumio Plugin failed to start in a timely fashion Dec 19 16:03:34 tycshd volumio[712]: [Metrics] CommandRouter: 52s 664.43ms Dec 19 16:03:34 tycshd volumio[712]: info: CoreCommandRouter::volumiosetStartupVolume Dec 19 16:03:34 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 16:03:34 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 16:03:34 tycshd volumio[712]: info: CoreCommandRouter::Close All Modals sent Dec 19 16:03:34 tycshd volumio[712]: info: CoreCommandRouter::Close All Modals sent Dec 19 16:03:35 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 19 16:03:35 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 19 16:03:35 tycshd volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 19 16:03:35 tycshd volumio[712]: info: Volumio called home Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=info msg="zeroconf server listening on port 39589" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="obtained new client token: AACtSfBW1nMUDiCRPad5i3/o7FRA/VbHdldHKHVi7T8IV9FzzIF+I65CFIlahBMYf2dSVP+SenOMKUmGVNJ7dwFtUAw+wn17HnC3N6f84ciHVbV0bZSlKFOQcqoyIWXF8kK20AkYBRIDyV9s6sk/JbtTKt6nMT5ZLMZuGhka5ZdYkq10VzhPshQRfC1KaB3SlyPWMZ2s1nhAwjY0WsIKxsvrT7RfmxD8HD5KMrLdIYqkG8lSxPinLgc=" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="completed keyexchange" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="completed challenge" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=info msg="authenticated AP" username="ty**rc" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=info msg="authenticated Login5" username="ty**rc" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="initializing zeroconf session" username="ty**rc" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="dealer connection opened" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=trace msg="starting accesspoint recv loop" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=trace msg="starting dealer recv loop" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=trace msg="received accesspoint ping" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=debug msg="received connection id: ZDAxN2IyMDUtYTc1...NDc3NDBGNzk3QQ==" Dec 19 16:03:35 tycshd go-librespot[1271]: time="2025-12-19T16:03:35+01:00" level=trace msg="received accesspoint pong ack" Dec 19 16:03:36 tycshd go-librespot[1271]: time="2025-12-19T16:03:36+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 19 16:03:36 tycshd go-librespot[1271]: time="2025-12-19T16:03:36+01:00" level=debug msg="update volume requested to 39976/65535" Dec 19 16:03:36 tycshd go-librespot[1271]: time="2025-12-19T16:03:36+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 19 16:03:36 tycshd go-librespot[1271]: time="2025-12-19T16:03:36+01:00" level=trace msg="emitting websocket event: volume" Dec 19 16:03:37 tycshd volumio[712]: info: Discovery: adding 120ce0ca-4893-4538-b389-bf03232d172c Dec 19 16:03:37 tycshd volumio[712]: info: Discovery: Found device TycSHD Dec 19 16:03:37 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:37 tycshd volumio[712]: info: MRS: Pushing multiroomSync output for this device Dec 19 16:03:37 tycshd volumio[712]: info: MRS: Pushing multiroomSync output Dec 19 16:03:37 tycshd volumio[712]: info: Adding audio output: Dec 19 16:03:37 tycshd volumio[712]: info: Adding audio output: Dec 19 16:03:37 tycshd volumio[712]: 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 19 16:03:37 tycshd volumio[712]: info: MRS: Found cast device: SHIELD-Android-TV-c6dde03b445cc32d88335767d45226ca Dec 19 16:03:37 tycshd volumio[712]: info: Adding audio output: Dec 19 16:03:37 tycshd volumio[712]: info: MRS: Found cast device: SHIELD-Android-TV-233c875739c080b993ec1b2f5eacb137 Dec 19 16:03:37 tycshd volumio[712]: info: Adding audio output: Dec 19 16:03:37 tycshd go-librespot[1271]: time="2025-12-19T16:03:37+01:00" level=debug msg="new websocket client" Dec 19 16:03:37 tycshd volumio[712]: 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 19 16:03:37 tycshd volumio[712]: info: Connection to go-librespot Websocket established Dec 19 16:03:37 tycshd volumio[712]: 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 19 16:03:37 tycshd volumio[712]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 19 16:03:37 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:38 tycshd volumio[712]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="handling transfer player command from 6aa28e9d4ea946233f53eaf9970444a1165ed1d9" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="resolved context of track" uri="spotify:user:tyc0rc:collection" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=trace msg="fetched new page 0 with 737 items (list: 737)" uri="spotify:user:tyc0rc:collection" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="loading track (paused: true, position: 123839ms)" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=trace msg="emitting websocket event: will_play" Dec 19 16:03:38 tycshd volumio[712]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:user:tyc0rc:collection","uri":"spotify:track:4gTFHQpidAuSjo5voOV5cG","play_origin":"playlist"}} Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="selected format OGG_VORBIS_320 (3bb7162ba58787306033c94b04156bdf88551d00)" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="requested aes key for file 3bb7162ba58787306033c94b04156bdf88551d00, gid: 4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 415" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1273" Dec 19 16:03:38 tycshd go-librespot[1271]: time="2025-12-19T16:03:38+01:00" level=debug msg="fetched first chunk of 12, total size is 5993184 bytes" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 11/11, size: 226016" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 10/11, size: 524288" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 9/11, size: 524288" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="seek to 123839ms (diff: 183ms, samples: 5461299, bytes: 4935638)" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="created new output device" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=info msg="loaded track \"Ameno (Techno Mix)\" (paused: true, position: 123839ms, duration: 150400ms, prefetched: false)" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="emitting websocket event: metadata" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="emitting websocket event: active" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="sending successful reply for dealer request" Dec 19 16:03:39 tycshd volumio[712]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4gTFHQpidAuSjo5voOV5cG","name":"Ameno (Techno Mix)","artist_names":["Gabry Ponte","Marnik","Roberto Molinaro"],"album_name":"Ameno (Techno Mix)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02db8c451eedac7c6149b88b5f","position":123839,"duration":150400,"release_date":"year:2023 month:12 day:22","track_number":1,"disc_number":1}} Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 19 16:03:39 tycshd volumio[712]: SPOTIFY: received: {"type":"active","data":null} Dec 19 16:03:39 tycshd volumio[712]: info: Aligning Spotify Volume to Volumio Volume Dec 19 16:03:39 tycshd volumio[712]: info: CoreCommandRouter::volumioGetState Dec 19 16:03:39 tycshd volumio[712]: info: Setting Spotify Volume from Volumio: 61 Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="emitting websocket event: paused" Dec 19 16:03:39 tycshd volumio[712]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:user:tyc0rc:collection","uri":"spotify:track:4gTFHQpidAuSjo5voOV5cG","play_origin":"playlist"}} Dec 19 16:03:39 tycshd volumio[712]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 16:03:39 tycshd volumio[712]: TypeError: Cannot read property 'service' of undefined Dec 19 16:03:39 tycshd volumio[712]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Dec 19 16:03:39 tycshd volumio[712]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Dec 19 16:03:39 tycshd volumio[712]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Dec 19 16:03:39 tycshd volumio[712]: at WebSocket.emit (events.js:400:28) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.emit (events.js:400:28) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 19 16:03:39 tycshd volumio[712]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 19 16:03:39 tycshd volumio[712]: at writeOrBuffer (internal/streams/writable.js:358:12) Dec 19 16:03:39 tycshd volumio[712]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Dec 19 16:03:39 tycshd volumio[712]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Dec 19 16:03:39 tycshd volumio[712]: at Socket.emit (events.js:400:28) Dec 19 16:03:39 tycshd volumio[712]: at addChunk (internal/streams/readable.js:293:12) Dec 19 16:03:39 tycshd volumio[712]: at readableAddChunk (internal/streams/readable.js:267:9) Dec 19 16:03:39 tycshd volumio[712]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="handling resume player command from 6aa28e9d4ea946233f53eaf9970444a1165ed1d9" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="seek to 123839ms (diff: 183ms, samples: 5461299, bytes: 4935638)" uri="spotify:track:4gTFHQpidAuSjo5voOV5cG" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="resume track at 123656ms" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="sending successful reply for dealer request" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="prefetching next track" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="selected format OGG_VORBIS_320 (b9523c3174cc31ae70d9d815e6b51c5b9513f683)" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="requested aes key for file b9523c3174cc31ae70d9d815e6b51c5b9513f683, gid: 78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 19 16:03:39 tycshd go-librespot[1271]: time="2025-12-19T16:03:39+01:00" level=trace msg="emitting websocket event: playing" Dec 19 16:03:40 tycshd go-librespot[1271]: time="2025-12-19T16:03:40+01:00" level=debug msg="fetched first chunk of 16, total size is 8359308 bytes" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:40 tycshd go-librespot[1271]: time="2025-12-19T16:03:40+01:00" level=info msg="prefetched track \"Out of Control\" (duration: 170400ms)" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:40 tycshd sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-19 16:02 Dec 19 16:03:40 tycshd sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 19 16:03:40 tycshd go-librespot[1271]: time="2025-12-19T16:03:40+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:40 tycshd go-librespot[1271]: time="2025-12-19T16:03:40+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" Dec 19 16:03:40 tycshd go-librespot[1271]: time="2025-12-19T16:03:40+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:78GFKnGSRPUIKG1huKpIyh" PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 18 Nov 2025 04:14:14 PM CET" VOLUMIO_VERSION="3.877" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="57978c68a391dbf6badbe915e5672a72"