Feb 17 10:52:15 volumiogang ntpd[1038]: CLOCK: time stepped by 2917.438203 Feb 17 10:52:15 volumiogang ntpd[1038]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Feb 17 10:52:16 volumiogang volumio[1216]: info: MYVOLUMIO Environment detected Feb 17 10:52:16 volumiogang volumio[1216]: info: Plugin folders cleanup Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning into folder /volumio/app/plugins/ Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category audio_interface Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category miscellanea Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category music_service Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category plugins.json Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category system_controller Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category user_interface Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning into folder /data/plugins/ Feb 17 10:52:16 volumiogang volumio[1216]: info: Scanning category music_service Feb 17 10:52:16 volumiogang volumio[1216]: info: Plugin folders cleanup completed Feb 17 10:52:16 volumiogang volumio[1216]: info: ------------------------------------------- Feb 17 10:52:16 volumiogang volumio[1216]: info: ----- Core plugins startup ---- Feb 17 10:52:16 volumiogang volumio[1216]: info: ------------------------------------------- Feb 17 10:52:16 volumiogang volumio[1216]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 10:52:16 volumiogang volumio[1216]: info: Adding plugin upnp to MyMusic Plugins Feb 17 10:52:16 volumiogang volumio[1216]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 10:52:16 volumiogang volumio[1216]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 10:52:16 volumiogang volumio[1216]: info: Loading plugins from folder /data/plugins/ Feb 17 10:52:16 volumiogang volumio[1216]: info: Loading plugin "system"... Feb 17 10:52:16 volumiogang volumio[1216]: info: Loading plugin "appearance"... Feb 17 10:52:17 volumiogang dhcpcd[679]: timed out Feb 17 10:52:17 volumiogang sh[675]: timed out Feb 17 10:52:17 volumiogang sh[619]: ifup: failed to bring up eth0 Feb 17 10:52:17 volumiogang systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:52:17 volumiogang systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 17 10:52:19 volumiogang systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Feb 17 10:52:19 volumiogang systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "network"... Feb 17 10:52:19 volumiogang systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:19 volumiogang volumio[1216]: info: Refreshing Cached IP Addresses Feb 17 10:52:19 volumiogang upmpdcli[1369]: Could not open config: /tmp/upmpdcli.conf Feb 17 10:52:19 volumiogang systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:52:19 volumiogang systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 17 10:52:19 volumiogang sudo[1373]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 10:52:19 volumiogang sudo[1373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:19 volumiogang sudo[1373]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:19 volumiogang sudo[1371]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 10:52:19 volumiogang sudo[1371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "services"... Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "volumio5onboarding"... Feb 17 10:52:19 volumiogang sudo[1371]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "alsa_controller"... Feb 17 10:52:19 volumiogang sudo[1382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 10:52:19 volumiogang sudo[1382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:19 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "wizard"... Feb 17 10:52:19 volumiogang volumio[1216]: info: Loading plugin "networkfs"... Feb 17 10:52:20 volumiogang volumio[1216]: info: Starting Udev Watcher for removable devices Feb 17 10:52:20 volumiogang sudo[1405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Stefan,password=61313324a1-N,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //10.10.22.2/Netzwerklaufwerk/Musik /mnt/NAS/NAS Feb 17 10:52:20 volumiogang sudo[1405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:20 volumiogang volumio[1216]: info: Ignoring mount for partition: boot Feb 17 10:52:20 volumiogang volumio[1216]: info: Ignoring mount for partition: volumio Feb 17 10:52:20 volumiogang volumio[1216]: info: Ignoring mount for partition: volumio_data Feb 17 10:52:20 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 10:52:20 volumiogang volumio[1216]: info: Loading plugin "volumio_command_line_client"... Feb 17 10:52:20 volumiogang volumio[1216]: info: Loading plugin "upnp"... Feb 17 10:52:20 volumiogang volumio[1216]: info: [1771321940268] Starting Upmpd Daemon Feb 17 10:52:20 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 10:52:20 volumiogang volumio[1216]: info: Loading plugin "my_music"... Feb 17 10:52:20 volumiogang volumio[1216]: info: Loading plugin "mpd"... Feb 17 10:52:20 volumiogang kernel: netfs: FS-Cache loaded Feb 17 10:52:20 volumiogang systemd[1]: systemd-hostnamed.service: Deactivated successfully. Feb 17 10:52:20 volumiogang kernel: Key type cifs.spnego registered Feb 17 10:52:20 volumiogang kernel: Key type cifs.idmap registered Feb 17 10:52:20 volumiogang kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Feb 17 10:52:20 volumiogang kernel: CIFS: Attempting to mount //10.10.22.2/Netzwerklaufwerk/Musik Feb 17 10:52:20 volumiogang volumio-remote-updater[696]: [2026-02-17 10:52:20] [connect] Successful connection Feb 17 10:52:21 volumiogang volumio[1216]: info: Loading plugin "upnp_browser"... Feb 17 10:52:21 volumiogang sudo[1405]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:23 volumiogang sudo[1382]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:24 volumiogang volumio[1216]: info: Starting UPNP Browser Feb 17 10:52:24 volumiogang volumio[1216]: info: Loading plugin "alarm-clock"... Feb 17 10:52:24 volumiogang volumio[1216]: info: Loading plugin "airplay_emulation"... Feb 17 10:52:25 volumiogang volumio[1216]: info: Starting Shairport Sync Feb 17 10:52:25 volumiogang volumio[1216]: info: Loading plugin "last_100"... Feb 17 10:52:25 volumiogang volumio[1216]: info: Loading plugin "webradio"... Feb 17 10:52:25 volumiogang volumio[1216]: info: Loading plugin "i2s_dacs"... Feb 17 10:52:25 volumiogang volumio[1216]: info: I2S DAC not set, start Auto-detection Feb 17 10:52:25 volumiogang volumio[1216]: info: Loading plugin "volumiodiscovery"... Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** For more information see Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** For more information see Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 10:52:25 volumiogang volumio[1216]: *** WARNING *** For more information see Feb 17 10:52:25 volumiogang node[1216]: *** WARNING *** For more information see Feb 17 10:52:25 volumiogang volumio[1216]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 10:52:25 volumiogang volumio[1216]: info: Discovery: Started advertising with name: VolumioGang Feb 17 10:52:25 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 10:52:25 volumiogang volumio[1216]: info: Loading plugin "spop"... Feb 17 10:52:29 volumiogang systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 17 10:52:29 volumiogang volumio[1216]: info: Loading plugin "youtube2"... Feb 17 10:52:31 volumiogang systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 17 10:52:31 volumiogang systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 17 10:52:31 volumiogang systemd[1]: setdatetime-helper.service: Consumed 1.291s CPU time. Feb 17 10:52:31 volumiogang volumio[1216]: info: Loading plugin "outputs"... Feb 17 10:52:31 volumiogang volumio[1216]: info: Loading plugin "albumart"... Feb 17 10:52:31 volumiogang volumio[1216]: info: Plugin example_plugin is not enabled Feb 17 10:52:31 volumiogang volumio[1216]: info: Loading plugin "inputs"... Feb 17 10:52:31 volumiogang volumio[1216]: info: Loading plugin "updater_comm"... Feb 17 10:52:32 volumiogang volumio[1216]: info: Plugin mpdemulation is not enabled Feb 17 10:52:32 volumiogang volumio[1216]: info: Loading plugin "rest_api"... Feb 17 10:52:32 volumiogang volumio[1216]: info: Loading plugin "websocket"... Feb 17 10:52:32 volumiogang volumio[1216]: info: Starting Socket.io Server version 1.7.4 Feb 17 10:52:32 volumiogang volumio[1216]: info: Loading plugin "80s80s"... Feb 17 10:52:33 volumiogang volumio[1487]: Forking 3 albumart workers Feb 17 10:52:33 volumiogang volumio[1216]: info: Applying required configuration parameters for plugin 80s80s Feb 17 10:52:33 volumiogang volumio[1216]: info: [1771321953839] [80s80s] API delay: 30 Feb 17 10:52:33 volumiogang volumio[1216]: info: Loading i18n strings for locale de Feb 17 10:52:34 volumiogang volumio[1216]: Updating browse sources language Feb 17 10:52:34 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:34 volumiogang systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Feb 17 10:52:34 volumiogang systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:34 volumiogang systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:34 volumiogang upmpdcli[1524]: Could not open config: /tmp/upmpdcli.conf Feb 17 10:52:34 volumiogang systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:52:34 volumiogang systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 17 10:52:35 volumiogang volumio-remote-updater[696]: [2026-02-17 10:52:35] [connect] Successful connection Feb 17 10:52:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 10:52:36 volumiogang volumio[1216]: info: CoreCommandRouter::initPlayerControls Feb 17 10:52:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: Express server listening on port 3000 Feb 17 10:52:37 volumiogang volumio[1216]: [Metrics] WebUI: 24s 184.77ms Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreStateMachine::resetVolumioState Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreStateMachine::getcurrentVolume Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 10:52:37 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:37 volumiogang volumio[1216]: info: Cannot read play queue from file Feb 17 10:52:38 volumiogang sudo[1535]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 10:52:38 volumiogang sudo[1535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:38 volumiogang sudo[1534]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 10:52:38 volumiogang sudo[1534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:38 volumiogang sudo[1535]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:38 volumiogang sudo[1534]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:38 volumiogang volumio[1216]: info: Volumio Network Manager: Network status updated: 2 Feb 17 10:52:39 volumiogang volumio[1216]: info: VolumeController:: Volume=86 Mute =false Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreStateMachine::pushState Feb 17 10:52:39 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreCommandRouter::volumioPushState Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreStateMachine::updateTrackBlock Feb 17 10:52:39 volumiogang volumio[1216]: info: CorePlayQueue::getTrackBlock Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 10:52:39 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:39 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:40 volumiogang volumio[1216]: verbose: New Socket.io Connection to 10.10.22.24:3000 from 10.10.22.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 17 10:52:41 volumiogang volumio[1216]: info: Setting Device type: Raspberry PI Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreStateMachine::setRepeat null single undefined Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreStateMachine::pushState Feb 17 10:52:41 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreCommandRouter::volumioPushState Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreStateMachine::setRandom null Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreStateMachine::pushState Feb 17 10:52:41 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:41 volumiogang volumio[1216]: info: CoreCommandRouter::volumioPushState Feb 17 10:52:41 volumiogang volumio[1216]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 17 10:52:41 volumiogang volumio[1216]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Feb 17 10:52:41 volumiogang volumio[1216]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 17 10:52:41 volumiogang volumio[1216]: info: Listing playlists Feb 17 10:52:41 volumiogang volumio[1216]: info: Listing playlists Feb 17 10:52:41 volumiogang volumio[1216]: verbose: New Socket.io Connection to 10.10.22.24:3000 from 10.10.22.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 17 10:52:42 volumiogang volumio[1216]: info: VolumeController:: Volume=86 Mute =false Feb 17 10:52:42 volumiogang volumio[1216]: info: CoreStateMachine::pushState Feb 17 10:52:42 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:42 volumiogang volumio[1216]: info: CoreCommandRouter::volumioPushState Feb 17 10:52:42 volumiogang volumio[1216]: info: Discovery: adding dff1cdce-f8f7-4a9a-ab6f-4d0e5e773776 Feb 17 10:52:42 volumiogang volumio[1216]: info: Discovery: Found device VolumioGang Feb 17 10:52:42 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:42 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:42 volumiogang volumio[1216]: verbose: New Socket.io Connection to 10.10.22.24:3000 from 10.10.22.23 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 17 10:52:42 volumiogang sudo[1566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 10:52:42 volumiogang sudo[1566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:42 volumiogang volumio[1216]: info: Discovery: this is already registered, dff1cdce-f8f7-4a9a-ab6f-4d0e5e773776 Feb 17 10:52:42 volumiogang volumio[1216]: info: Discovery: Found device VolumioGang Feb 17 10:52:42 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:42 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:42 volumiogang volumio[1216]: info: Completed loading Core Plugins Feb 17 10:52:42 volumiogang volumio[1216]: info: Preparing to generate the ALSA configuration file Feb 17 10:52:43 volumiogang volumio[1216]: info: Discovery: adding daf796e7-cf94-4680-8b3e-0cc60084888a Feb 17 10:52:43 volumiogang volumio[1216]: info: Discovery: Found device Volumio Feb 17 10:52:43 volumiogang volumio[1216]: info: Discovery: Connecting to remote: 10.10.22.23 Feb 17 10:52:43 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Feb 17 10:52:44 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:44 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:44 volumiogang volumio[1216]: info: Asound.conf file unchanged, so no further update is needed Feb 17 10:52:44 volumiogang volumio[1216]: info: Output device has changed, restarting MPD Feb 17 10:52:44 volumiogang volumio[1216]: info: Output device has changed, restarting Shairport Sync Feb 17 10:52:44 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:44 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:44 volumiogang sudo[1571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 10:52:44 volumiogang sudo[1571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:44 volumiogang sudo[1569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 10:52:44 volumiogang sudo[1569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:44 volumiogang volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 10:52:44 volumiogang volumio[1216]: info: ___________ START PLUGINS ___________ Feb 17 10:52:44 volumiogang sudo[1569]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:44 volumiogang volumio[1216]: info: ControllerMpd::onStart: Initializing MPD Feb 17 10:52:44 volumiogang volumio[1216]: info: Creating MPD Configuration file Feb 17 10:52:45 volumiogang systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 10:52:45 volumiogang systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 10:52:45 volumiogang sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 10:52:45 volumiogang sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:45 volumiogang sudo[1582]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:45 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 10:52:45 volumiogang volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 10:52:45 volumiogang volumio[1216]: info: [1771321965241] CoreMusicLibrary::Adding element Medienserver Feb 17 10:52:45 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:45 volumiogang sudo[1583]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 10:52:45 volumiogang sudo[1583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 10:52:45 volumiogang sudo[1587]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 17 10:52:45 volumiogang sudo[1583]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:45 volumiogang sudo[1579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 17 10:52:45 volumiogang sudo[1579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:45 volumiogang volumio[1216]: info: UPNP Browser: Client initialized successfully Feb 17 10:52:45 volumiogang sudo[1586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 10:52:45 volumiogang sudo[1586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:45 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:45 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:46 volumiogang systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:52:46 volumiogang sudo[1579]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:46 volumiogang systemd[1]: mpd.service: Deactivated successfully. Feb 17 10:52:46 volumiogang systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 10:52:46 volumiogang systemd[1]: mpd.socket: Deactivated successfully. Feb 17 10:52:46 volumiogang systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 10:52:46 volumiogang systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 10:52:46 volumiogang systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 10:52:46 volumiogang volumio[1499]: Starting albumart workers Feb 17 10:52:46 volumiogang systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 10:52:46 volumiogang volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:46 volumiogang sudo[1597]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 10:52:46 volumiogang sudo[1597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 10:52:46 volumiogang sudo[1607]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 17 10:52:46 volumiogang sudo[1597]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:46 volumiogang volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 10:52:46 volumiogang volumio[1216]: info: [1771321966549] CoreMusicLibrary::Adding element Last_100 Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:46 volumiogang volumio[1498]: Starting albumart workers Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 10:52:46 volumiogang volumio[1216]: info: [1771321966673] CoreMusicLibrary::Adding element Webradio Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:46 volumiogang volumio5-onboarding[1592]: time=2026-02-17T10:52:46.763+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 17 10:52:46 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 10:52:46 volumiogang volumio[1216]: info: Initializing BBC Radios Feb 17 10:52:47 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 10:52:47 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:47 volumiogang volumio[1497]: Starting albumart workers Feb 17 10:52:47 volumiogang volumio[1216]: info: Creating Spotify config file Feb 17 10:52:47 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:47 volumiogang volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 10:52:47 volumiogang volumio[1216]: info: [1771321967968] CoreMusicLibrary::Adding element YouTube2 Feb 17 10:52:47 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:47 volumiogang volumio[1216]: Cannot find translation for source YouTube2 Feb 17 10:52:48 volumiogang volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 10:52:48 volumiogang volumio[1216]: info: [1771321968206] CoreMusicLibrary::Adding element 80s80s Radio Feb 17 10:52:48 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 10:52:48 volumiogang volumio[1216]: Cannot find translation for source YouTube2 Feb 17 10:52:48 volumiogang volumio[1216]: Cannot find translation for source 80s80s Radio Feb 17 10:52:48 volumiogang volumio[1216]: info: Volumio Calling Home Feb 17 10:52:49 volumiogang systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Feb 17 10:52:49 volumiogang systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:49 volumiogang systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 17 10:52:49 volumiogang sudo[1566]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:50 volumiogang volumio-remote-updater[696]: [2026-02-17 10:52:50] [connect] Successful connection Feb 17 10:52:55 volumiogang mpd[1608]: 2026-02-17T10:52:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 10:52:55 volumiogang systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 10:52:55 volumiogang sudo[1571]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:55 volumiogang sudo[1586]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:55 volumiogang volumio[1216]: info: Discovery: Connected to remote: 10.10.22.23 Feb 17 10:52:55 volumiogang volumio[1216]: info: MPD Permissions set Feb 17 10:52:55 volumiogang volumio[1216]: info: MPD Permissions set Feb 17 10:52:55 volumiogang volumio[1216]: info: Upmpdcli Daemon Started Feb 17 10:52:55 volumiogang volumio[1216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 17 10:52:56 volumiogang volumio[1216]: info: Completed starting Core Plugins Feb 17 10:52:56 volumiogang volumio[1216]: info: ------------------------------------------- Feb 17 10:52:56 volumiogang volumio[1216]: info: ----- MyVolumio plugins startup ---- Feb 17 10:52:56 volumiogang volumio[1216]: info: ------------------------------------------- Feb 17 10:52:56 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 10:52:56 volumiogang volumio[1216]: info: Volumio called home Feb 17 10:52:56 volumiogang volumio[1216]: info: Spotify config file written Feb 17 10:52:56 volumiogang volumio[1216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Feb 17 10:52:56 volumiogang volumio[1216]: info: Received Get System Info Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 10:52:56 volumiogang volumio[1216]: info: Discovery: Getting this device information Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:56 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 10:52:56 volumiogang volumio5-onboarding[1592]: time=2026-02-17T10:52:56.215+01:00 level=INFO msg="system info for 7bf60936400fa1069687e6c08c62780b" deviceName=VolumioGang deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang sudo[1681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 10:52:56 volumiogang sudo[1681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 10:52:56 volumiogang systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 10:52:56 volumiogang systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 10:52:56 volumiogang go-librespot[1691]: go-librespot daemon starting... Feb 17 10:52:56 volumiogang sudo[1681]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 10:52:56 volumiogang volumio[1216]: info: No need to fix Spotify hosts Feb 17 10:52:56 volumiogang volumio[1216]: info: Received Get System Info Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 10:52:56 volumiogang volumio[1216]: info: Discovery: Getting this device information Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:56 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 10:52:56 volumiogang volumio[1216]: error: MPD error: The expression evaluated to a falsy value: Feb 17 10:52:56 volumiogang volumio[1216]: assert.ok(self.idling) Feb 17 10:52:56 volumiogang volumio[1216]: error: The expression evaluated to a falsy value: Feb 17 10:52:56 volumiogang volumio[1216]: assert.ok(self.idling) Feb 17 10:52:56 volumiogang volumio[1216]: info: MPD running with PID1608 Feb 17 10:52:56 volumiogang volumio[1216]: ,establishing connection Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 17 10:52:56 volumiogang volumio[1216]: error: updateQueue error: null Feb 17 10:52:56 volumiogang volumio[1216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 17 10:52:56 volumiogang volumio5-onboarding[1592]: time=2026-02-17T10:52:56.969+01:00 level=INFO msg="enabling local network discovery" Feb 17 10:52:56 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:56 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:57 volumiogang volumio[1216]: info: Starting Shairport Sync Feb 17 10:52:57 volumiogang volumio5-onboarding[1592]: time=2026-02-17T10:52:57.047+01:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 17 10:52:57 volumiogang volumio[1216]: info: Starting Shairport Sync Feb 17 10:52:57 volumiogang volumio[1216]: info: Starting Shairport Sync Feb 17 10:52:57 volumiogang volumio[1216]: error: updateQueue error: null Feb 17 10:52:57 volumiogang volumio[1216]: info: Listing playlists Feb 17 10:52:57 volumiogang sudo[1706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 10:52:57 volumiogang sudo[1706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:57 volumiogang volumio[1216]: info: Listing playlists Feb 17 10:52:57 volumiogang volumio[1216]: info: Received Get System Info Feb 17 10:52:57 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 17 10:52:57 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+01:00" level=info msg="running go-librespot 0.6.2" Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+01:00" level=debug msg="app state loaded" Feb 17 10:52:57 volumiogang volumio[1216]: info: Discovery: Getting this device information Feb 17 10:52:57 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:57 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:57 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+01:00" level=debug msg="stored credentials not found" Feb 17 10:52:57 volumiogang sudo[1707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 10:52:57 volumiogang sudo[1707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:57 volumiogang sudo[1709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 10:52:57 volumiogang systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 10:52:57 volumiogang systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 10:52:57 volumiogang systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 10:52:57 volumiogang systemd[1]: shairport-sync.service: Consumed 1.649s CPU time. Feb 17 10:52:57 volumiogang sudo[1709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:52:57 volumiogang systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 10:52:57 volumiogang sudo[1707]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:57 volumiogang systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 10:52:57 volumiogang systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 10:52:57 volumiogang systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 10:52:57 volumiogang volumio[1216]: info: Shairport-Sync Started Feb 17 10:52:57 volumiogang volumio[1216]: Error adding Membership: Error: addMembership EINVAL Feb 17 10:52:57 volumiogang systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 10:52:57 volumiogang sudo[1709]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:57 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:52:57 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:52:57 volumiogang volumio[1216]: info: Shairport-Sync Started Feb 17 10:52:57 volumiogang sudo[1706]: pam_unix(sudo:session): session closed for user root Feb 17 10:52:57 volumiogang volumio[1216]: info: Shairport-Sync Started Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+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]" Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+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]" Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+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]" Feb 17 10:52:57 volumiogang go-librespot[1695]: time="2026-02-17T10:52:57+01:00" level=info msg="zeroconf server listening on port 44093" Feb 17 10:53:00 volumiogang volumio[1216]: info: go-librespot daemon successfully initialized Feb 17 10:53:01 volumiogang volumio[1216]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 10:53:03 volumiogang volumio[1216]: info: Initializing connection to go-librespot Websocket Feb 17 10:53:03 volumiogang go-librespot[1695]: time="2026-02-17T10:53:03+01:00" level=debug msg="new websocket client" Feb 17 10:53:03 volumiogang volumio[1216]: info: Connection to go-librespot Websocket established Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 10:53:05 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 10:53:05 volumiogang volumio-remote-updater[696]: [2026-02-17 10:53:05] [connect] Successful connection Feb 17 10:53:18 volumiogang volumio[1216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 10:53:18 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 10:53:18 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:53:18 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:53:18 volumiogang volumio[1216]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 10:53:18 volumiogang volumio[1216]: info: MyVolumio login type: Token Feb 17 10:53:18 volumiogang volumio[1216]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 10:53:18 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 10:53:20 volumiogang volumio-remote-updater[696]: [2026-02-17 10:53:20] [connect] Successful connection Feb 17 10:53:27 volumiogang volumio5-onboarding[1592]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Feb 17 10:53:27 volumiogang systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:53:27 volumiogang systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 17 10:53:27 volumiogang systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Feb 17 10:53:27 volumiogang systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:27 volumiogang systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:27 volumiogang volumio5-onboarding[1780]: time=2026-02-17T10:53:27.438+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 17 10:53:33 volumiogang go-librespot[1695]: time="2026-02-17T10:53:33+01:00" level=debug msg="obtained new client token: AAC8YicqfYoLrjVrAdlOM6WFudHD2nvoYQd1WXCitrj8PSVUsZDI/J8NrhAm6Zptn5Ev/ThiFTkE4VUe11Qns3TvvGK7V0EymeOngqD7kicZmLDzGQV1ynkJr5MhHt+jjV60A3zRzpEjWoCcJ+h+bqfBn50eR7zC+i7GslaarcxxeeAPRYQCHkvjtoib8Hjie/GYjvg7yC8kx46/m1dxN3/pNXvC6Es494BFav/k0SH7g4Q3ayUhtuFe" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="completed keyexchange" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="completed challenge" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=info msg="authenticated AP" username="s_**ll" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=info msg="authenticated Login5" username="s_**ll" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=info msg="accepted zeroconf from ALL-IN-ONE" username="s_**ll" Feb 17 10:53:34 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 10:53:34 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 10:53:34 volumiogang volumio[1216]: info: Streaming services startup Feb 17 10:53:34 volumiogang volumio[1216]: info: Starting Streaming Daemon Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="dealer connection opened" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="starting accesspoint recv loop" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="starting dealer recv loop" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="received accesspoint ping" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="received connection id: YzdhMmUzMjYtOTIy...NUNFNDY1RkY4OQ==" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="received accesspoint pong ack" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="handling transfer player command from 98fa15df7c56026dde4ce18b017de3d2cda12611" Feb 17 10:53:34 volumiogang volumio[1216]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 10:53:34 volumiogang sudo[1805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 10:53:34 volumiogang sudo[1805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="resolved context of track" uri="spotify:station:playlist:10cNznZDSZrn8RyIkBcXRG" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:station:playlist:10cNznZDSZrn8RyIkBcXRG" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="loading track (paused: true, position: 41169ms)" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=trace msg="emitting websocket event: will_play" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 17 10:53:34 volumiogang go-librespot[1695]: time="2026-02-17T10:53:34+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1328" Feb 17 10:53:35 volumiogang go-librespot[1695]: time="2026-02-17T10:53:35+01:00" level=debug msg="selected format OGG_VORBIS_320 (f3e1c7187e64932c846da814efa4a1d402f74398)" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:35 volumiogang go-librespot[1695]: time="2026-02-17T10:53:35+01:00" level=debug msg="requested aes key for file f3e1c7187e64932c846da814efa4a1d402f74398, gid: 3g5KynFpso7C2taJnbihsX" Feb 17 10:53:35 volumiogang go-librespot[1695]: time="2026-02-17T10:53:35+01:00" level=trace msg="found 3 cdn urls" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:35 volumiogang go-librespot[1695]: time="2026-02-17T10:53:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1110" Feb 17 10:53:35 volumiogang sudo[1805]: pam_unix(sudo:session): session closed for user root Feb 17 10:53:35 volumiogang go-librespot[1695]: time="2026-02-17T10:53:35+01:00" level=debug msg="fetched first chunk of 19, total size is 9570394 bytes" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:35 volumiogang volumio[1216]: info: Getting Spotify volume Feb 17 10:53:35 volumiogang volumio-remote-updater[696]: [2026-02-17 10:53:35] [connect] Successful connection Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 10:53:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=trace msg="seek to 41169ms (diff: 218ms, samples: 1815552, bytes: 1826205)" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="created new output device" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=info msg="loaded track \"Gelber Schein\" (paused: true, position: 41169ms, duration: 213571ms, prefetched: false)" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:36 volumiogang volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=trace msg="emitting websocket event: metadata" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=trace msg="emitting websocket event: active" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="sending successful reply for dealer request" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 17 10:53:36 volumiogang go-librespot[1695]: time="2026-02-17T10:53:36+01:00" level=trace msg="emitting websocket event: paused" Feb 17 10:53:36 volumiogang volumio[1216]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:playlist:10cNznZDSZrn8RyIkBcXRG","uri":"spotify:track:3g5KynFpso7C2taJnbihsX","play_origin":""}} Feb 17 10:53:36 volumiogang volumio[1216]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3g5KynFpso7C2taJnbihsX","name":"Gelber Schein","artist_names":["Mittel Alta"],"album_name":"Gelber Schein","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027fa06138acbf749798a77583","position":41169,"duration":213571,"release_date":"year:2025 month:1 day:24","track_number":1,"disc_number":1}} Feb 17 10:53:36 volumiogang volumio[1216]: SPOTIFY: received: {"type":"active","data":null} Feb 17 10:53:36 volumiogang volumio[1216]: info: Aligning Spotify Volume to Volumio Volume Feb 17 10:53:36 volumiogang volumio[1216]: info: CoreCommandRouter::volumioGetState Feb 17 10:53:36 volumiogang volumio[1216]: info: CorePlayQueue::getTrack 0 Feb 17 10:53:36 volumiogang volumio[1216]: info: Setting Spotify Volume from Volumio: 86 Feb 17 10:53:36 volumiogang volumio[1216]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:station:playlist:10cNznZDSZrn8RyIkBcXRG","uri":"spotify:track:3g5KynFpso7C2taJnbihsX","play_origin":""}} Feb 17 10:53:36 volumiogang volumio[1216]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 10:53:36 volumiogang volumio[1216]: TypeError: Cannot read properties of undefined (reading 'service') Feb 17 10:53:36 volumiogang volumio[1216]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 17 10:53:36 volumiogang volumio[1216]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Feb 17 10:53:36 volumiogang volumio[1216]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 17 10:53:36 volumiogang volumio[1216]: at WebSocket.emit (node:events:514:28) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver.emit (node:events:514:28) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 17 10:53:36 volumiogang volumio[1216]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 17 10:53:36 volumiogang volumio[1216]: at writeOrBuffer (node:internal/streams/writable:399:12) Feb 17 10:53:36 volumiogang volumio[1216]: at _write (node:internal/streams/writable:340:10) Feb 17 10:53:36 volumiogang volumio[1216]: at Writable.write (node:internal/streams/writable:344:10) Feb 17 10:53:36 volumiogang volumio[1216]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 17 10:53:36 volumiogang volumio[1216]: at Socket.emit (node:events:514:28) Feb 17 10:53:36 volumiogang volumio[1216]: at addChunk (node:internal/streams/readable:343:12) Feb 17 10:53:37 volumiogang volumio[1216]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 10:53:37 volumiogang volumio5-onboarding[1780]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:40318->127.0.0.1:3000: i/o timeout Feb 17 10:53:37 volumiogang systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:53:37 volumiogang systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 17 10:53:37 volumiogang systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Feb 17 10:53:37 volumiogang systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:37 volumiogang systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:37 volumiogang volumio5-onboarding[1825]: time=2026-02-17T10:53:37.908+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=debug msg="handling resume player command from 98fa15df7c56026dde4ce18b017de3d2cda12611" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=trace msg="seek to 41169ms (diff: 218ms, samples: 1815552, bytes: 1826205)" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+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" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=debug msg="resume track at 40702ms" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=trace msg="scheduling prefetch in 142s" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=debug msg="sending successful reply for dealer request" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 17 10:53:38 volumiogang go-librespot[1695]: time="2026-02-17T10:53:38+01:00" level=trace msg="emitting websocket event: playing" Feb 17 10:53:43 volumiogang go-librespot[1695]: time="2026-02-17T10:53:43+01:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:3g5KynFpso7C2taJnbihsX" Feb 17 10:53:47 volumiogang sudo[1851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 10:52' Feb 17 10:53:47 volumiogang sudo[1851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 10:53:47 volumiogang volumio5-onboarding[1825]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:42576->127.0.0.1:3000: i/o timeout Feb 17 10:53:47 volumiogang systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 17 10:53:47 volumiogang systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 17 10:53:48 volumiogang systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 3. Feb 17 10:53:48 volumiogang systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:48 volumiogang systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 17 10:53:48 volumiogang volumio5-onboarding[1853]: time=2026-02-17T10:53:48.415+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"