-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sun 2026-05-31 07:52:55 CEST. -- May 31 07:52:41 switje systemd-timedated[1018]: Changed local time to Sun May 31 07:52:41 2026 May 31 07:52:41 switje sudo[1016]: pam_unix(sudo:session): session closed for user root May 31 07:52:41 switje volumio-time-update[599]: volumio-time-update-util: System time updated successfully. May 31 07:52:41 switje systemd[1]: Starting Daily man-db regeneration... May 31 07:52:41 switje systemd[1]: Starting Daily apt download activities... May 31 07:52:41 switje systemd[1]: Started Volumio Time Update Utility. May 31 07:52:41 switje volumio[981]: info: Loading plugin "network"... May 31 07:52:41 switje volumio[981]: info: Refreshing Cached IP Addresses May 31 07:52:41 switje sudo[1042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 31 07:52:41 switje sudo[1042]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:41 switje sudo[1042]: pam_unix(sudo:session): session closed for user root May 31 07:52:41 switje sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 31 07:52:41 switje sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:41 switje sudo[1044]: pam_unix(sudo:session): session closed for user root May 31 07:52:41 switje volumio[981]: info: Loading plugin "services"... May 31 07:52:41 switje systemd[1]: man-db.service: Succeeded. May 31 07:52:41 switje systemd[1]: Started Daily man-db regeneration. May 31 07:52:41 switje volumio[981]: info: Loading plugin "volumio5onboarding"... May 31 07:52:41 switje sudo[1053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 31 07:52:41 switje sudo[1053]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:41 switje volumio[981]: info: Loading plugin "alsa_controller"... May 31 07:52:41 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 07:52:41 switje volumio[981]: info: Loading plugin "wizard"... May 31 07:52:41 switje volumio[981]: info: Loading plugin "networkfs"... May 31 07:52:41 switje nmbd[751]: [2026/05/31 07:52:41.653558, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 31 07:52:41 switje nmbd[751]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 31 07:52:41 switje systemd[1]: Started Samba NMB Daemon. May 31 07:52:41 switje nmbd[751]: [2026/05/31 07:52:41.676384, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 31 07:52:41 switje nmbd[751]: query_name_response: Multiple (2) responses received for a query on subnet 10.2.10.81 for name WORKGROUP<1d>. May 31 07:52:41 switje nmbd[751]: This response was from IP 10.2.10.44, reporting an IP address of 10.2.10.44. May 31 07:52:41 switje volumio[981]: info: Starting Udev Watcher for removable devices May 31 07:52:41 switje sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=lodewijk,password=Landmeters.12,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //10.2.10.110/music /mnt/NAS/switje May 31 07:52:41 switje sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:41 switje systemd[1]: Starting Samba Winbind Daemon... May 31 07:52:41 switje volumio[981]: info: Ignoring mount for partition: boot May 31 07:52:41 switje volumio[981]: info: Ignoring mount for partition: volumio May 31 07:52:41 switje volumio[981]: info: Ignoring mount for partition: volumio_data May 31 07:52:41 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 07:52:41 switje volumio[981]: info: Loading plugin "volumio_command_line_client"... May 31 07:52:41 switje volumio[981]: info: Loading plugin "upnp"... May 31 07:52:41 switje volumio[981]: info: [1780206761746] Starting Upmpd Daemon May 31 07:52:41 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 07:52:41 switje volumio[981]: info: Loading plugin "my_music"... May 31 07:52:41 switje volumio[981]: info: Loading plugin "mpd"... May 31 07:52:41 switje systemd[1]: apt-daily.service: Succeeded. May 31 07:52:41 switje systemd[1]: Started Daily apt download activities. May 31 07:52:41 switje kernel: Key type cifs.spnego registered May 31 07:52:41 switje kernel: Key type cifs.idmap registered May 31 07:52:41 switje 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. May 31 07:52:41 switje kernel: CIFS: Attempting to mount //10.2.10.110/music May 31 07:52:41 switje systemd[1]: Starting Daily apt upgrade and clean activities... May 31 07:52:41 switje winbindd[1086]: [2026/05/31 07:52:41.976183, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 31 07:52:41 switje winbindd[1086]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 31 07:52:42 switje winbindd[1086]: [2026/05/31 07:52:42.008403, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 31 07:52:42 switje winbindd[1086]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 31 07:52:42 switje systemd[1]: Started Samba Winbind Daemon. May 31 07:52:42 switje systemd[1]: Starting Samba SMB Daemon... May 31 07:52:42 switje volumio[981]: info: Loading plugin "upnp_browser"... May 31 07:52:42 switje smbd[1141]: [2026/05/31 07:52:42.439625, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 31 07:52:42 switje systemd[1]: Started Samba SMB Daemon. May 31 07:52:42 switje smbd[1141]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 31 07:52:42 switje systemd[1]: Reached target Multi-User System. May 31 07:52:42 switje systemd[1]: Reached target Graphical Interface. May 31 07:52:42 switje systemd[1]: Starting Update UTMP about System Runlevel Changes... May 31 07:52:42 switje systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 31 07:52:42 switje systemd[1]: Started Update UTMP about System Runlevel Changes. May 31 07:52:42 switje systemd[1]: apt-daily-upgrade.service: Succeeded. May 31 07:52:42 switje systemd[1]: Started Daily apt upgrade and clean activities. May 31 07:52:42 switje systemd[1]: Startup finished in 11.884s (kernel) + 25.596s (userspace) = 37.481s. May 31 07:52:42 switje volumio[981]: info: Starting UPNP Browser May 31 07:52:42 switje volumio[981]: info: Loading plugin "alarm-clock"... May 31 07:52:42 switje volumio[981]: info: Loading plugin "airplay_emulation"... May 31 07:52:42 switje sudo[1091]: pam_unix(sudo:session): session closed for user root May 31 07:52:42 switje volumio[981]: info: Starting Shairport Sync May 31 07:52:42 switje volumio[981]: info: Loading plugin "last_100"... May 31 07:52:42 switje volumio[981]: info: Loading plugin "webradio"... May 31 07:52:42 switje volumio[981]: info: Loading plugin "i2s_dacs"... May 31 07:52:42 switje volumio[981]: info: I2S DAC not set, start Auto-detection May 31 07:52:42 switje volumio[981]: info: Loading plugin "volumiodiscovery"... May 31 07:52:42 switje volumio[981]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 31 07:52:42 switje volumio[981]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 07:52:42 switje node[981]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 31 07:52:42 switje volumio[981]: *** WARNING *** For more information see May 31 07:52:42 switje volumio[981]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 31 07:52:42 switje volumio[981]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 07:52:42 switje volumio[981]: *** WARNING *** For more information see May 31 07:52:42 switje node[981]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 07:52:42 switje node[981]: *** WARNING *** For more information see May 31 07:52:42 switje node[981]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 31 07:52:42 switje node[981]: *** WARNING *** Please fix your application to use the native API of Avahi! May 31 07:52:42 switje node[981]: *** WARNING *** For more information see May 31 07:52:42 switje volumio[981]: info: Applying required configuration parameters for plugin volumiodiscovery May 31 07:52:42 switje volumio[981]: info: Discovery: Started advertising with name: Switje May 31 07:52:42 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 31 07:52:42 switje volumio[981]: info: Loading plugin "spop"... May 31 07:52:43 switje volumio-remote-updater[600]: [2026-05-31 07:52:43] [connect] Successful connection May 31 07:52:43 switje volumio[981]: info: Loading plugin "now_playing"... May 31 07:52:44 switje volumio[981]: info: Loading plugin "outputs"... May 31 07:52:44 switje volumio[981]: info: Loading plugin "albumart"... May 31 07:52:44 switje volumio[981]: info: Plugin example_plugin is not enabled May 31 07:52:44 switje volumio[981]: info: Loading plugin "inputs"... May 31 07:52:44 switje volumio[981]: info: Loading plugin "updater_comm"... May 31 07:52:45 switje volumio[981]: info: Plugin mpdemulation is not enabled May 31 07:52:45 switje volumio[981]: info: Loading plugin "rest_api"... May 31 07:52:45 switje volumio[981]: info: Loading plugin "websocket"... May 31 07:52:45 switje volumio[981]: info: Starting Socket.io Server version 2.3.0 May 31 07:52:45 switje volumio[981]: info: Loading plugin "touch_display"... May 31 07:52:45 switje volumio[981]: Forking 3 albumart workers May 31 07:52:45 switje sudo[1053]: pam_unix(sudo:session): session closed for user root May 31 07:52:45 switje volumio[981]: info: Applying required configuration parameters for plugin touch_display May 31 07:52:45 switje volumio[981]: Starting albumart workers May 31 07:52:45 switje volumio[981]: Starting albumart workers May 31 07:52:45 switje volumio[981]: Starting albumart workers May 31 07:52:45 switje volumio[981]: info: Loading i18n strings for locale nl May 31 07:52:45 switje volumio[981]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 07:52:45 switje volumio[981]: Updating browse sources language May 31 07:52:45 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::initPlayerControls May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 07:52:46 switje volumio[981]: Express server listening on port 3000 May 31 07:52:46 switje volumio[981]: [Metrics] WebUI: 7s 89.10ms May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::resetVolumioState May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::getcurrentVolume May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioRetrievevolume May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:46 switje volumio[981]: info: Volumio Network Manager: Network status updated: 2 May 31 07:52:46 switje volumio-remote-updater[600]: [2026-05-31 07:52:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1780206763 101 May 31 07:52:46 switje volumio[981]: 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 May 31 07:52:46 switje volumio[981]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 31 07:52:46 switje volumio[981]: info: Reloading queue from file May 31 07:52:46 switje volumio[981]: info: VolumeController:: Volume=20 Mute =false May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::pushState May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioPushState May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::updateTrackBlock May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrackBlock May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioRetrievevolume May 31 07:52:46 switje volumio[981]: info: Setting Device type: Raspberry PI May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::setRepeat true single undefined May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::pushState May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioPushState May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::setRandom false May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::pushState May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioPushState May 31 07:52:46 switje volumio[981]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb May 31 07:52:46 switje volumio[981]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 May 31 07:52:46 switje volumio[981]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI May 31 07:52:46 switje volumio[981]: info: VolumeController:: Volume=20 Mute =false May 31 07:52:46 switje volumio[981]: info: CoreStateMachine::pushState May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioPushState May 31 07:52:46 switje volumio[981]: info: Completed loading Core Plugins May 31 07:52:46 switje volumio[981]: info: Preparing to generate the ALSA configuration file May 31 07:52:46 switje volumio[981]: info: Discovery: adding 7bf9cf3b-d2c0-48d9-9bc9-0a14ff74e840 May 31 07:52:46 switje volumio[981]: info: Discovery: Found device Switje May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:46 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:46 switje volumio[981]: info: Asound.conf file unchanged, so no further update is needed May 31 07:52:46 switje volumio[981]: info: Output device has changed, restarting MPD May 31 07:52:46 switje sudo[1264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 07:52:46 switje sudo[1264]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje volumio[981]: info: Output device has changed, restarting Shairport Sync May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:46 switje sudo[1264]: pam_unix(sudo:session): session closed for user root May 31 07:52:46 switje sudo[1266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 07:52:46 switje sudo[1266]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje volumio[981]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 07:52:46 switje volumio[981]: info: ___________ START PLUGINS ___________ May 31 07:52:46 switje volumio[981]: info: ControllerMpd::onStart: Initializing MPD May 31 07:52:46 switje volumio[981]: info: Creating MPD Configuration file May 31 07:52:46 switje sudo[1274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service May 31 07:52:46 switje sudo[1274]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 07:52:46 switje volumio[981]: info: [1780206766562] CoreMusicLibrary::Adding element Media Servers May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 07:52:46 switje sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 07:52:46 switje sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje sudo[1277]: pam_unix(sudo:session): session closed for user root May 31 07:52:46 switje systemd[1]: Listening on mpd.socket. May 31 07:52:46 switje systemd[1]: Starting Music Player Daemon... May 31 07:52:46 switje sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 07:52:46 switje volumio[981]: info: UPNP Browser: Client initialized successfully May 31 07:52:46 switje sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:46 switje systemd[1]: Started Volumio5 Onboarding Server. May 31 07:52:46 switje sudo[1274]: pam_unix(sudo:session): session closed for user root May 31 07:52:46 switje systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 31 07:52:46 switje systemd[1]: mpd.service: Succeeded. May 31 07:52:46 switje systemd[1]: Stopped Music Player Daemon. May 31 07:52:46 switje systemd[1]: Starting Music Player Daemon... May 31 07:52:46 switje volumio[981]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:46 switje volumio[981]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 07:52:46 switje volumio[981]: info: [1780206766680] CoreMusicLibrary::Adding element Last_100 May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 07:52:46 switje volumio[981]: info: [1780206766683] CoreMusicLibrary::Adding element Webradio May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 07:52:46 switje volumio[981]: info: Initializing BBC Radios May 31 07:52:46 switje sudo[1287]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 07:52:46 switje sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje sudo[1287]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory May 31 07:52:46 switje sudo[1287]: pam_unix(sudo:session): session closed for user root May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:46 switje volumio[981]: info: Creating Spotify config file May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:46 switje volumio[981]: info: [now-playing] ConfigUpdater: config is up to date. May 31 07:52:46 switje volumio[981]: info: Loading i18n strings for locale nl May 31 07:52:46 switje volumio[981]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. May 31 07:52:46 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 31 07:52:46 switje volumio[981]: info: Volumio Calling Home May 31 07:52:46 switje sudo[1312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service May 31 07:52:46 switje sudo[1312]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje sudo[1314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service May 31 07:52:46 switje sudo[1314]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload May 31 07:52:46 switje sudo[1316]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:46 switje volumio[981]: info: [now-playing] App is listening on port 4004. May 31 07:52:47 switje volumio[981]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds May 31 07:52:47 switje volumio[981]: info: touch_display: Backlight interface detected. May 31 07:52:47 switje volumio[981]: info: MPD Permissions set May 31 07:52:47 switje volumio[981]: info: MPD Permissions set May 31 07:52:47 switje volumio[981]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 31 07:52:47 switje volumio[981]: info: Spotify config file written May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.063+02:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z May 31 07:52:47 switje volumio[981]: info: Volumio called home May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje systemd[1]: Reloading. May 31 07:52:47 switje sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 31 07:52:47 switje sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 07:52:47 switje volumio[981]: info: No need to fix Spotify hosts May 31 07:52:47 switje volumio[981]: 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 May 31 07:52:47 switje volumio[981]: info: touch_display: Raspberry Pi Foundation touch screen detected. May 31 07:52:47 switje sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness May 31 07:52:47 switje sudo[1352]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje volumio[981]: 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 May 31 07:52:47 switje sudo[1352]: pam_unix(sudo:session): session closed for user root May 31 07:52:47 switje sudo[1348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf May 31 07:52:47 switje sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje volumio[981]: info: Received Get System Info May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 07:52:47 switje volumio[981]: info: Discovery: Getting this device information May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:47 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.347+02:00 level=INFO msg="system info for a7103cf31bc0be8b2c193371d29c5f27" deviceName=Switje deviceVariant=volumio deviceModel= softwareVersion=3.912 May 31 07:52:47 switje sudo[1348]: pam_unix(sudo:session): session closed for user root May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:47 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:47 switje volumio[981]: info: Starting Shairport Sync May 31 07:52:47 switje volumio[981]: info: Starting Shairport Sync May 31 07:52:47 switje volumio[981]: info: Starting Shairport Sync May 31 07:52:47 switje sudo[1358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 07:52:47 switje volumio[981]: info: Received Get System Info May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 07:52:47 switje volumio[981]: info: Discovery: Getting this device information May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:47 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 07:52:47 switje sudo[1356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 07:52:47 switje sudo[1358]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje sudo[1356]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje sudo[1360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 07:52:47 switje sudo[1360]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 31 07:52:47 switje volumio[981]: info: touch_display: File permissions for backlight brightness control set. May 31 07:52:47 switje volumio[981]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.569+02:00 level=INFO msg="enabling local network discovery" May 31 07:52:47 switje volumio[981]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 31 07:52:47 switje volumio[981]: SPOTIFY: BQCyEnt3TO7Tzez-QDjPDUbQ735mrH5oMJGkOFZvdLT_5raOLd-Wds_SosxJ9Z1vzny7u31XWTHSeBO1YTUFFVadpjlaaAziYczcx8-VuuT3YjpKgMsa4IR7kCbAQf-12e_anb1leB3qV3ROwwroaiM_tnUc_i-AD8NjNDg_Q6qEdVL-oqIE1eM8harZZa7Q9S40l6TAmztcZ58wcnBCg4NLcTg_UL-8lX7G68mPqZlQERTK4TJbZugR0bZUqm3W3yBBO-Y4l0qSs1sicGSxhl_C6obTZVphRnwVew May 31 07:52:47 switje volumio[981]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 31 07:52:47 switje volumio[981]: info: New Spotify access token = BQCyEnt3TO7Tzez-QDjPDUbQ735mrH5oMJGkOFZvdLT_5raOLd-Wds_SosxJ9Z1vzny7u31XWTHSeBO1YTUFFVadpjlaaAziYczcx8-VuuT3YjpKgMsa4IR7kCbAQf-12e_anb1leB3qV3ROwwroaiM_tnUc_i-AD8NjNDg_Q6qEdVL-oqIE1eM8harZZa7Q9S40l6TAmztcZ58wcnBCg4NLcTg_UL-8lX7G68mPqZlQERTK4TJbZugR0bZUqm3W3yBBO-Y4l0qSs1sicGSxhl_C6obTZVphRnwVew May 31 07:52:47 switje volumio[981]: info: Spotify credentials grant success - running version from March 24, 2019 May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.585+02:00 level=INFO msg="enabling BLE discovery" May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.648+02:00 level=INFO msg="bootstrapping state" hasInternet=true May 31 07:52:47 switje volumio[981]: info: Received Get System Info May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 07:52:47 switje volumio[981]: info: Discovery: Getting this device information May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:47 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 07:52:47 switje volumio-remote-updater[600]: No test mode May 31 07:52:47 switje volumio-remote-updater[600]: No alpha test mode May 31 07:52:47 switje systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 31 07:52:47 switje volumio[981]: SPOTIFY: User informations: {"account_id":"Lz8zknEeX9","country":"BE","display_name":"1124370079","email":"lode_90@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1124370079"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/1124370079","id":"1124370079","images":[],"product":"premium","type":"user","uri":"spotify:user:1124370079"} May 31 07:52:47 switje volumio[981]: info: Spotify Successfully logged in May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 31 07:52:47 switje volumio[981]: info: [1780206767767] CoreMusicLibrary::Adding element Spotify May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 07:52:47 switje volumio[981]: Cannot find translation for source Spotify May 31 07:52:47 switje volumio[981]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.797+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.799+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" May 31 07:52:47 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:47.799+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 07:52:47 switje volumio[981]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 07:52:47 switje sudo[1316]: pam_unix(sudo:session): session closed for user root May 31 07:52:47 switje volumio[981]: info: touch_display: systemctl daemon-reload succeeded. May 31 07:52:47 switje sudo[1312]: pam_unix(sudo:session): session closed for user root May 31 07:52:47 switje sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service May 31 07:52:47 switje sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:47 switje systemd[1]: Reloading. May 31 07:52:47 switje volumio[981]: info: touch_display: systemctl stop getty@tty1.service succeeded. May 31 07:52:48 switje systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 31 07:52:48 switje sudo[1314]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje volumio[981]: info: touch_display: systemctl disable getty@tty1.service succeeded. May 31 07:52:48 switje systemd[1]: Started Volumio Kiosk. May 31 07:52:48 switje sudo[1380]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 31 07:52:48 switje volumio[981]: info: touch_display: systemctl start volumio-kiosk.service succeeded. May 31 07:52:48 switje volumio[981]: info: touch_display: Volumio Kiosk started. May 31 07:52:48 switje systemd[1]: Started go-librespot Daemon. May 31 07:52:48 switje sudo[1322]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje go-librespot[1428]: go-librespot daemon starting... May 31 07:52:48 switje systemd[1]: shairport-sync.service: Succeeded. May 31 07:52:48 switje systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 31 07:52:48 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:48 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:48 switje volumio5-onboarding[1286]: time=2026-05-31T07:52:48.764+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 31 07:52:48 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:48 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:48 switje volumio[981]: info: touch_display: X display number found: May 31 07:52:48 switje systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 31 07:52:48 switje sudo[1358]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje sudo[1356]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje volumio[981]: info: Shairport-Sync Started May 31 07:52:48 switje sudo[1360]: pam_unix(sudo:session): session closed for user root May 31 07:52:48 switje volumio[981]: Error adding Membership: Error: addMembership EINVAL May 31 07:52:48 switje volumio[981]: info: Shairport-Sync Started May 31 07:52:48 switje volumio[981]: info: Shairport-Sync Started May 31 07:52:48 switje volumio[981]: info: touch_display: X display number found: 0 May 31 07:52:49 switje volumio[981]: info: touch_display: X display number found: 0 May 31 07:52:49 switje startx[1425]: X.Org X Server 1.20.4 May 31 07:52:49 switje startx[1425]: X Protocol Version 11, Revision 0 May 31 07:52:49 switje startx[1425]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian May 31 07:52:49 switje startx[1425]: Current Operating System: Linux switje 6.6.62-v7l+ #1816 SMP Mon Nov 18 15:33:33 GMT 2024 armv7l May 31 07:52:49 switje startx[1425]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:FC:FD:58 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=8543fa12-4125-4451-a534-cec5480e0606 imgfile=/volumio_current.sqsh bootpart=UUID=9C48-E5A3 datapart=UUID=f7cca1c6-391b-47a8-9c19-3b1948539def uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no May 31 07:52:49 switje startx[1425]: Build Date: 04 April 2023 07:50:56AM May 31 07:52:49 switje startx[1425]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) May 31 07:52:49 switje startx[1425]: Current version of pixman: 0.36.0 May 31 07:52:49 switje startx[1425]: Before reporting problems, check http://wiki.x.org May 31 07:52:49 switje startx[1425]: to make sure that you have the latest version. May 31 07:52:49 switje startx[1425]: Markers: (--) probed, (**) from config file, (==) default setting, May 31 07:52:49 switje startx[1425]: (++) from command line, (!!) notice, (II) informational, May 31 07:52:49 switje startx[1425]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. May 31 07:52:49 switje startx[1425]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun May 31 07:52:49 2026 May 31 07:52:49 switje mpd[1294]: May 31 07:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 07:52:49 switje startx[1425]: (==) Using config directory: "/etc/X11/xorg.conf.d" May 31 07:52:49 switje startx[1425]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" May 31 07:52:49 switje volumio[981]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 May 31 07:52:49 switje volumio[981]: info: touch_display: X display number found: 0 May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=info msg="running go-librespot 0.4.0" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="app state loaded" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 31 07:52:49 switje systemd[1]: Started Music Player Daemon. May 31 07:52:49 switje sudo[1279]: pam_unix(sudo:session): session closed for user root May 31 07:52:49 switje sudo[1266]: pam_unix(sudo:session): session closed for user root May 31 07:52:49 switje volumio[981]: info: Completed starting Core Plugins May 31 07:52:49 switje volumio[981]: info: ------------------------------------------- May 31 07:52:49 switje volumio[981]: info: ----- MyVolumio plugins startup ---- May 31 07:52:49 switje volumio[981]: info: ------------------------------------------- May 31 07:52:49 switje volumio[981]: info: [MyVolumio PluginManager] Fetching plans data.... May 31 07:52:49 switje volumio[981]: info: MPD running with PID1294 May 31 07:52:49 switje volumio[981]: ,establishing connection May 31 07:52:49 switje volumio[981]: error: MPD error: The expression evaluated to a falsy value: May 31 07:52:49 switje volumio[981]: assert.ok(self.idling) May 31 07:52:49 switje volumio[981]: error: The expression evaluated to a falsy value: May 31 07:52:49 switje volumio[981]: assert.ok(self.idling) May 31 07:52:49 switje volumio[981]: error: MPD error: The expression evaluated to a falsy value: May 31 07:52:49 switje volumio[981]: assert.ok(self.idling) May 31 07:52:49 switje volumio[981]: error: The expression evaluated to a falsy value: May 31 07:52:49 switje volumio[981]: assert.ok(self.idling) May 31 07:52:49 switje volumio[981]: error: updateQueue error: null May 31 07:52:49 switje systemd[1]: systemd-fsckd.service: Succeeded. May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=info msg="zeroconf server listening on port 41489" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="obtained new client token: AABO5aLJ2MBuZ517378v8Axc31VUCglwmqjh6rhIsPdcLLASxDGFyHdfFKO5vhAaE6z6B1aIcAN5JfkTTN6XX08TKPkocXRzBSBF1Sl4sqMwgME6Zr94BchcN0RG2EBP9tFpLiRZP0T8SxiKou5YBPmKPqJNPpBdt/z0qkBPgB+zotI3BNq5iMcmWXJBZa+tArNPyEvclHwjRjBc+XREGZtDWcm84cISdVo5lih40gHwuJpCj7krpSfLFwl2" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="completed keyexchange" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="completed challenge" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=info msg="authenticated AP" username="11******79" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=info msg="authenticated Login5" username="11******79" May 31 07:52:49 switje go-librespot[1428]: time="2026-05-31T07:52:49+02:00" level=debug msg="initializing zeroconf session" username="11******79" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="dealer connection opened" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=trace msg="starting accesspoint recv loop" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=trace msg="starting dealer recv loop" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=trace msg="received accesspoint ping" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="received connection id: YmUwNzY3YWYtOTdk...MkI3QzlGMTkxNw==" May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=trace msg="received accesspoint pong ack" May 31 07:52:50 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:50 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:50 switje go-librespot[1428]: time="2026-05-31T07:52:50+02:00" level=debug msg="put connect state because NEW_DEVICE" May 31 07:52:50 switje volumio[981]: info: touch_display: Setting screensaver timeout to 120 seconds. May 31 07:52:50 switje sh[515]: timed out May 31 07:52:50 switje dhcpcd[566]: timed out May 31 07:52:50 switje sh[515]: dhcpcd exited May 31 07:52:50 switje dhcpcd[566]: dhcpcd exited May 31 07:52:50 switje sh[515]: ifup: failed to bring up eth0 May 31 07:52:50 switje systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE May 31 07:52:50 switje systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. May 31 07:52:51 switje sudo[1599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 31 07:52:51 switje sudo[1599]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:51 switje sudo[1599]: pam_unix(sudo:session): session closed for user root May 31 07:52:51 switje volumio[981]: info: go-librespot daemon successfully initialized May 31 07:52:51 switje sudo[1602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 31 07:52:51 switje sudo[1602]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:51 switje sudo[1602]: pam_unix(sudo:session): session closed for user root May 31 07:52:51 switje sudo[1605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 31 07:52:51 switje sudo[1605]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 07:52:51 switje systemd[1]: Started UPnP Renderer front-end to MPD. May 31 07:52:51 switje sudo[1605]: pam_unix(sudo:session): session closed for user root May 31 07:52:51 switje volumio[981]: info: Upmpdcli Daemon Started May 31 07:52:52 switje volumio[1607]: Generating RSA private key, 4096 bit long modulus (2 primes) May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=debug msg="handling transfer player command from 64638574082ed70bbc5920f558329792c5829410" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:0gWHiWNLMLXLzD5YyJUSjw" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=trace msg="fetched new page 0 with 106 items (list: 106)" uri="spotify:playlist:0gWHiWNLMLXLzD5YyJUSjw" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=debug msg="shuffled context with seed 1171317677262964269 (len: 106, keep: 93)" uri="spotify:playlist:0gWHiWNLMLXLzD5YyJUSjw" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=debug msg="loading track (paused: false, position: 75562ms)" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 07:52:53 switje go-librespot[1428]: time="2026-05-31T07:52:53+02:00" level=trace msg="emitting websocket event: will_play" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="selected format OGG_VORBIS_320 (2fd32d48c8b8e74d04d2371269575de91af05912)" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="requested aes key for file 2fd32d48c8b8e74d04d2371269575de91af05912, gid: 0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1229" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="fetched first chunk of 18, total size is 9021824 bytes" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:54 switje volumio[981]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:54 switje volumio[981]: Cannot compose Albumart path May 31 07:52:54 switje volumio[981]: info: Initializing connection to go-librespot Websocket May 31 07:52:54 switje go-librespot[1428]: time="2026-05-31T07:52:54+02:00" level=debug msg="new websocket client" May 31 07:52:54 switje volumio[981]: info: Connection to go-librespot Websocket established May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 6/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 5/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 4/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=trace msg="seek to 75562ms (diff: 183ms, samples: 3332284, bytes: 2569390)" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="created new output device" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02: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" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=info msg="loaded track \"Honey Drips Slow\" (paused: false, position: 75562ms, duration: 276961ms, prefetched: false)" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="fetched chunk 7/17, size: 524288" uri="spotify:track:0FMdaQHWGtBwMlEe4O3oeQ" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=trace msg="scheduling prefetch in 171s" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=trace msg="emitting websocket event: metadata" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=trace msg="emitting websocket event: active" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="sending successful reply for dealer request" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 31 07:52:55 switje volumio[981]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0FMdaQHWGtBwMlEe4O3oeQ","name":"Honey Drips Slow","artist_names":["Morgan Luna"],"album_name":"Honey Drips Slow","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e8a69098bddc4d10142764d3","position":75562,"duration":276961,"release_date":"year:2025 month:12 day:8","track_number":1,"disc_number":1}} May 31 07:52:55 switje volumio[981]: SPOTIFY: received: {"type":"active","data":null} May 31 07:52:55 switje volumio[981]: info: Aligning Spotify Volume to Volumio Volume May 31 07:52:55 switje volumio[981]: info: CoreCommandRouter::volumioGetState May 31 07:52:55 switje volumio[981]: info: CorePlayQueue::getTrack 0 May 31 07:52:55 switje volumio[981]: info: Setting Spotify Volume from Volumio: 20 May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 07:52:55 switje go-librespot[1428]: time="2026-05-31T07:52:55+02:00" level=trace msg="emitting websocket event: playing" May 31 07:52:55 switje volumio[981]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:0gWHiWNLMLXLzD5YyJUSjw","uri":"spotify:track:0FMdaQHWGtBwMlEe4O3oeQ","resume":false,"play_origin":"playlist/ondemand"}} May 31 07:52:55 switje volumio[981]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 07:52:55 switje volumio[981]: TypeError: Cannot read property 'service' of undefined May 31 07:52:55 switje volumio[981]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) May 31 07:52:55 switje volumio[981]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) May 31 07:52:55 switje volumio[981]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) May 31 07:52:55 switje volumio[981]: at WebSocket.emit (events.js:315:20) May 31 07:52:55 switje volumio[981]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 31 07:52:55 switje volumio[981]: at Receiver.emit (events.js:315:20) May 31 07:52:55 switje volumio[981]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 31 07:52:55 switje volumio[981]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 31 07:52:55 switje volumio[981]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 31 07:52:55 switje volumio[981]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 31 07:52:55 switje volumio[981]: at writeOrBuffer (internal/streams/writable.js:358:12) May 31 07:52:55 switje volumio[981]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 31 07:52:55 switje volumio[981]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 31 07:52:55 switje volumio[981]: at Socket.emit (events.js:315:20) May 31 07:52:55 switje volumio[981]: at addChunk (internal/streams/readable.js:309:12) May 31 07:52:55 switje volumio[981]: at readableAddChunk (internal/streams/readable.js:284:9) May 31 07:52:55 switje volumio[981]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 07:52:55 switje sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-31 07:51 May 31 07:52:55 switje sudo[1705]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"