-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Tue 2026-06-02 19:43:56 CEST. -- Jun 02 19:43:38 volumio-allo systemd-timedated[999]: Changed local time to Tue Jun 2 19:43:38 2026 Jun 02 19:43:38 volumio-allo sudo[997]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:38 volumio-allo volumio-time-update[545]: volumio-time-update-util: System time updated successfully. Jun 02 19:43:38 volumio-allo systemd[1]: Started Volumio Time Update Utility. Jun 02 19:43:38 volumio-allo systemd[1]: Starting Daily apt download activities... Jun 02 19:43:38 volumio-allo volumio[967]: info: MYVOLUMIO Environment detected Jun 02 19:43:38 volumio-allo volumio[967]: info: Plugin folders cleanup Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning into folder /volumio/app/plugins/ Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category audio_interface Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category miscellanea Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category music_service Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category plugins.json Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category system_controller Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category user_interface Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning into folder /data/plugins/ Jun 02 19:43:38 volumio-allo volumio[967]: info: Scanning category music_service Jun 02 19:43:38 volumio-allo volumio[967]: info: Plugin folders cleanup completed Jun 02 19:43:38 volumio-allo volumio[967]: info: ------------------------------------------- Jun 02 19:43:38 volumio-allo volumio[967]: info: ----- Core plugins startup ---- Jun 02 19:43:38 volumio-allo volumio[967]: info: ------------------------------------------- Jun 02 19:43:38 volumio-allo volumio[967]: info: Loading plugins from folder /volumio/app/plugins/ Jun 02 19:43:38 volumio-allo volumio[967]: info: Adding plugin upnp to MyMusic Plugins Jun 02 19:43:38 volumio-allo volumio[967]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 02 19:43:38 volumio-allo volumio[967]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 02 19:43:38 volumio-allo volumio[967]: info: Loading plugins from folder /data/plugins/ Jun 02 19:43:38 volumio-allo volumio[967]: info: Loading plugin "system"... Jun 02 19:43:38 volumio-allo volumio[967]: info: Loading plugin "appearance"... Jun 02 19:43:38 volumio-allo nmbd[740]: [2026/06/02 19:43:38.555322, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 02 19:43:38 volumio-allo systemd[1]: Started Samba NMB Daemon. Jun 02 19:43:38 volumio-allo nmbd[740]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jun 02 19:43:38 volumio-allo systemd[1]: Starting Samba Winbind Daemon... Jun 02 19:43:38 volumio-allo systemd[1]: apt-daily.service: Succeeded. Jun 02 19:43:38 volumio-allo systemd[1]: Started Daily apt download activities. Jun 02 19:43:38 volumio-allo systemd[1]: Starting Daily apt upgrade and clean activities... Jun 02 19:43:38 volumio-allo winbindd[1038]: [2026/06/02 19:43:38.860744, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jun 02 19:43:38 volumio-allo winbindd[1038]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jun 02 19:43:38 volumio-allo winbindd[1038]: [2026/06/02 19:43:38.890021, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 02 19:43:38 volumio-allo systemd[1]: Started Samba Winbind Daemon. Jun 02 19:43:38 volumio-allo winbindd[1038]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jun 02 19:43:38 volumio-allo systemd[1]: Starting Samba SMB Daemon... Jun 02 19:43:39 volumio-allo smbd[1066]: [2026/06/02 19:43:39.304483, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jun 02 19:43:39 volumio-allo systemd[1]: Started Samba SMB Daemon. Jun 02 19:43:39 volumio-allo smbd[1066]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jun 02 19:43:39 volumio-allo systemd[1]: Reached target Multi-User System. Jun 02 19:43:39 volumio-allo systemd[1]: Reached target Graphical Interface. Jun 02 19:43:39 volumio-allo systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 02 19:43:39 volumio-allo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 02 19:43:39 volumio-allo systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 02 19:43:39 volumio-allo systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 02 19:43:39 volumio-allo systemd[1]: Started Daily apt upgrade and clean activities. Jun 02 19:43:39 volumio-allo systemd[1]: Startup finished in 11.799s (kernel) + 25.446s (userspace) = 37.246s. Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "network"... Jun 02 19:43:39 volumio-allo volumio[967]: info: Refreshing Cached IP Addresses Jun 02 19:43:39 volumio-allo sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 02 19:43:39 volumio-allo sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:39 volumio-allo sudo[1118]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:39 volumio-allo sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 02 19:43:39 volumio-allo sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:39 volumio-allo sudo[1120]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "services"... Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "volumio5onboarding"... Jun 02 19:43:39 volumio-allo sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 02 19:43:39 volumio-allo sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "alsa_controller"... Jun 02 19:43:39 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "wizard"... Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "networkfs"... Jun 02 19:43:39 volumio-allo volumio[967]: info: Starting Udev Watcher for removable devices Jun 02 19:43:39 volumio-allo sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Gabor,password=xerxes,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.150/Adat /mnt/NAS/Adat Jun 02 19:43:39 volumio-allo sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:39 volumio-allo sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=2.1 //192.168.1.150/Adat1TB /mnt/NAS/Adat1TB Jun 02 19:43:39 volumio-allo sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:39 volumio-allo volumio[967]: info: Ignoring mount for partition: boot Jun 02 19:43:39 volumio-allo volumio[967]: info: Ignoring mount for partition: volumio Jun 02 19:43:39 volumio-allo volumio[967]: info: Ignoring mount for partition: volumio_data Jun 02 19:43:39 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "volumio_command_line_client"... Jun 02 19:43:39 volumio-allo volumio[967]: info: Loading plugin "upnp"... Jun 02 19:43:40 volumio-allo volumio[967]: info: [1780422220005] Starting Upmpd Daemon Jun 02 19:43:40 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "my_music"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "mpd"... Jun 02 19:43:40 volumio-allo kernel: Key type cifs.spnego registered Jun 02 19:43:40 volumio-allo kernel: Key type cifs.idmap registered Jun 02 19:43:40 volumio-allo 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. Jun 02 19:43:40 volumio-allo kernel: CIFS: Attempting to mount //192.168.1.150/Adat Jun 02 19:43:40 volumio-allo volumio-remote-updater[549]: [2026-06-02 19:43:40] [connect] Successful connection Jun 02 19:43:40 volumio-allo sudo[1146]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:40 volumio-allo kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Jun 02 19:43:40 volumio-allo kernel: CIFS: VFS: \\192.168.1.150 Send error in SessSetup = -13 Jun 02 19:43:40 volumio-allo kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Jun 02 19:43:40 volumio-allo kernel: CIFS: Attempting to mount //192.168.1.150/Adat1TB Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "upnp_browser"... Jun 02 19:43:40 volumio-allo sudo[1148]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:40 volumio-allo kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Jun 02 19:43:40 volumio-allo volumio[967]: info: Starting UPNP Browser Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "alarm-clock"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "airplay_emulation"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Starting Shairport Sync Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "last_100"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "webradio"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "i2s_dacs"... Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "volumiodiscovery"... Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** For more information see Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 19:43:40 volumio-allo volumio[967]: *** WARNING *** For more information see Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** For more information see Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 19:43:40 volumio-allo node[967]: *** WARNING *** For more information see Jun 02 19:43:40 volumio-allo volumio[967]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 02 19:43:40 volumio-allo volumio[967]: info: Discovery: Started advertising with name: Volumio Allo Jun 02 19:43:40 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 19:43:40 volumio-allo volumio[967]: info: Loading plugin "spop"... Jun 02 19:43:41 volumio-allo volumio[967]: info: Loading plugin "youtube2"... Jun 02 19:43:43 volumio-allo sudo[1130]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:44 volumio-allo volumio[967]: info: Loading plugin "ytmusic"... Jun 02 19:43:45 volumio-allo systemd[1]: systemd-fsckd.service: Succeeded. Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "outputs"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "albumart"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Plugin example_plugin is not enabled Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "inputs"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "updater_comm"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Plugin mpdemulation is not enabled Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "rest_api"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading plugin "websocket"... Jun 02 19:43:46 volumio-allo volumio[967]: info: Starting Socket.io Server version 2.3.0 Jun 02 19:43:46 volumio-allo volumio[967]: info: Loading i18n strings for locale hu Jun 02 19:43:46 volumio-allo volumio[967]: Updating browse sources language Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:46 volumio-allo volumio[967]: Forking 3 albumart workers Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::initPlayerControls Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 19:43:46 volumio-allo volumio[967]: Express server listening on port 3000 Jun 02 19:43:46 volumio-allo volumio[967]: [Metrics] WebUI: 9s 760.83ms Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreStateMachine::resetVolumioState Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreStateMachine::getcurrentVolume Jun 02 19:43:46 volumio-allo volumio[967]: info: CoreCommandRouter::volumioRetrievevolume Jun 02 19:43:46 volumio-allo volumio[967]: info: Volumio Network Manager: Network status updated: 2 Jun 02 19:43:46 volumio-allo volumio[967]: info: Cannot mount NAS Adat1TB at system boot, trial number 1 ,retrying in 5 seconds Jun 02 19:43:46 volumio-allo volumio[967]: info: Cannot mount NAS Adat at system boot, trial number 1 ,retrying in 5 seconds Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: Reloading queue from file Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::setRepeat true single undefined Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::pushState Jun 02 19:43:47 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioPushState Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::setRandom null Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::pushState Jun 02 19:43:47 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioPushState Jun 02 19:43:47 volumio-allo volumio[967]: info: Setting Device type: Raspberry PI Jun 02 19:43:47 volumio-allo volumio[967]: info: Completed loading Core Plugins Jun 02 19:43:47 volumio-allo volumio[967]: info: Preparing to generate the ALSA configuration file Jun 02 19:43:47 volumio-allo volumio[967]: info: VolumeController:: Volume=67 Mute =false Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::pushState Jun 02 19:43:47 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioPushState Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreStateMachine::updateTrackBlock Jun 02 19:43:47 volumio-allo volumio[967]: info: CorePlayQueue::getTrackBlock Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioRetrievevolume Jun 02 19:43:47 volumio-allo volumio[967]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 02 19:43:47 volumio-allo volumio[967]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Jun 02 19:43:47 volumio-allo volumio[967]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 02 19:43:47 volumio-allo volumio[967]: Starting albumart workers Jun 02 19:43:47 volumio-allo volumio[967]: info: Asound.conf file unchanged, so no further update is needed Jun 02 19:43:47 volumio-allo volumio[967]: info: Output device has changed, restarting MPD Jun 02 19:43:47 volumio-allo volumio[967]: Starting albumart workers Jun 02 19:43:47 volumio-allo volumio[967]: Starting albumart workers Jun 02 19:43:47 volumio-allo sudo[1230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 02 19:43:47 volumio-allo volumio[967]: info: Output device has changed, restarting Shairport Sync Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:47 volumio-allo sudo[1230]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo sudo[1230]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:47 volumio-allo sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 02 19:43:47 volumio-allo sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo volumio[967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 19:43:47 volumio-allo volumio[967]: info: ___________ START PLUGINS ___________ Jun 02 19:43:47 volumio-allo volumio[967]: info: ControllerMpd::onStart: Initializing MPD Jun 02 19:43:47 volumio-allo volumio[967]: info: Creating MPD Configuration file Jun 02 19:43:47 volumio-allo sh[496]: timed out Jun 02 19:43:47 volumio-allo dhcpcd[520]: timed out Jun 02 19:43:47 volumio-allo sh[496]: dhcpcd exited Jun 02 19:43:47 volumio-allo dhcpcd[520]: dhcpcd exited Jun 02 19:43:47 volumio-allo sh[496]: ifup: failed to bring up eth0 Jun 02 19:43:47 volumio-allo sudo[1239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Jun 02 19:43:47 volumio-allo sudo[1239]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:47 volumio-allo volumio[967]: info: [1780422227325] CoreMusicLibrary::Adding element Médiaszerverek Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:47 volumio-allo volumio[967]: info: UPNP Browser: Client initialized successfully Jun 02 19:43:47 volumio-allo sudo[1244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 02 19:43:47 volumio-allo sudo[1244]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:47 volumio-allo sudo[1244]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:47 volumio-allo sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:47 volumio-allo sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo systemd[1]: Listening on mpd.socket. Jun 02 19:43:47 volumio-allo systemd[1]: Starting Music Player Daemon... Jun 02 19:43:47 volumio-allo systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jun 02 19:43:47 volumio-allo systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jun 02 19:43:47 volumio-allo systemd[1]: Started Volumio5 Onboarding Server. Jun 02 19:43:47 volumio-allo sudo[1239]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:47 volumio-allo systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 02 19:43:47 volumio-allo systemd[1]: mpd.service: Succeeded. Jun 02 19:43:47 volumio-allo systemd[1]: Stopped Music Player Daemon. Jun 02 19:43:47 volumio-allo systemd[1]: Starting Music Player Daemon... Jun 02 19:43:47 volumio-allo volumio[967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:47 volumio-allo volumio[967]: info: [1780422227571] CoreMusicLibrary::Adding element Last_100 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:47 volumio-allo sudo[1254]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 02 19:43:47 volumio-allo sudo[1254]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:47 volumio-allo volumio[967]: info: [1780422227584] CoreMusicLibrary::Adding element Webradio Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 02 19:43:47 volumio-allo volumio[967]: info: Initializing BBC Radios Jun 02 19:43:47 volumio-allo sudo[1254]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jun 02 19:43:47 volumio-allo sudo[1254]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: Creating Spotify config file Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:47 volumio-allo volumio[967]: info: [1780422227849] CoreMusicLibrary::Adding element YouTube2 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:47 volumio-allo volumio[967]: Cannot find translation for source YouTube2 Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:47 volumio-allo volumio[967]: info: [1780422227855] CoreMusicLibrary::Adding element YouTube Music Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:47 volumio-allo volumio[967]: Cannot find translation for source YouTube2 Jun 02 19:43:47 volumio-allo volumio[967]: Cannot find translation for source YouTube Music Jun 02 19:43:47 volumio-allo volumio[967]: info: Volumio Calling Home Jun 02 19:43:47 volumio-allo volumio5-onboarding[1253]: time=2026-06-02T19:43:47.911+02:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Jun 02 19:43:47 volumio-allo volumio[967]: info: Discovery: adding a65bf7c1-481e-48da-a10c-91a22372a8df Jun 02 19:43:47 volumio-allo volumio[967]: info: Discovery: Found device Volumio Allo Jun 02 19:43:47 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:47 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:47 volumio-allo volumio[967]: info: MPD Permissions set Jun 02 19:43:47 volumio-allo volumio[967]: info: MPD Permissions set Jun 02 19:43:47 volumio-allo volumio[967]: 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: 1 Jun 02 19:43:48 volumio-allo volumio[967]: info: Spotify config file written Jun 02 19:43:48 volumio-allo volumio[967]: 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: 1 Jun 02 19:43:48 volumio-allo volumio[967]: info: Received Get System Info Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 02 19:43:48 volumio-allo volumio[967]: info: Discovery: Getting this device information Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:48 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 02 19:43:48 volumio-allo sudo[1307]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 02 19:43:48 volumio-allo sudo[1307]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:48 volumio-allo volumio5-onboarding[1253]: time=2026-06-02T19:43:48.043+02:00 level=INFO msg="system info for 5b638e8e3e9427b2b943e907a39181ed" deviceName="Volumio Allo" deviceVariant=volumio deviceModel= softwareVersion=3.912 Jun 02 19:43:48 volumio-allo volumio[967]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 19:43:48 volumio-allo volumio[967]: info: No need to fix Spotify hosts Jun 02 19:43:48 volumio-allo volumio[967]: info: Received Get System Info Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 02 19:43:48 volumio-allo volumio[967]: info: Discovery: Getting this device information Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:48 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 02 19:43:48 volumio-allo systemd[1]: Started go-librespot Daemon. Jun 02 19:43:48 volumio-allo go-librespot[1310]: go-librespot daemon starting... Jun 02 19:43:48 volumio-allo sudo[1307]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:48 volumio-allo volumio[967]: info: VolumeController:: Volume=67 Mute =false Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreStateMachine::pushState Jun 02 19:43:48 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioPushState Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 02 19:43:48 volumio-allo volumio5-onboarding[1253]: time=2026-06-02T19:43:48.171+02:00 level=INFO msg="enabling local network discovery" Jun 02 19:43:48 volumio-allo volumio[967]: info: Volumio called home Jun 02 19:43:48 volumio-allo volumio5-onboarding[1253]: time=2026-06-02T19:43:48.186+02:00 level=INFO msg="enabling BLE discovery" Jun 02 19:43:48 volumio-allo volumio[967]: info: Starting Shairport Sync Jun 02 19:43:48 volumio-allo volumio[967]: info: Starting Shairport Sync Jun 02 19:43:48 volumio-allo volumio[967]: info: Starting Shairport Sync Jun 02 19:43:48 volumio-allo sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 19:43:48 volumio-allo sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:48 volumio-allo sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 19:43:48 volumio-allo sudo[1324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 19:43:48 volumio-allo sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:48 volumio-allo sudo[1324]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:48 volumio-allo volumio5-onboarding[1253]: time=2026-06-02T19:43:48.272+02:00 level=INFO msg="bootstrapping state" hasInternet=true Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:48 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:48 volumio-allo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 02 19:43:48 volumio-allo systemd[1]: shairport-sync.service: Succeeded. Jun 02 19:43:48 volumio-allo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 02 19:43:48 volumio-allo volumio[967]: info: Received Get System Info Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 02 19:43:48 volumio-allo volumio[967]: info: Discovery: Getting this device information Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:48 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 02 19:43:48 volumio-allo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 02 19:43:48 volumio-allo sudo[1322]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:48 volumio-allo sudo[1324]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:48 volumio-allo sudo[1326]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:48 volumio-allo volumio[967]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 02 19:43:48 volumio-allo volumio[967]: SPOTIFY: BQBfT1k40ma25oNCS6Nd_y9rKVaZbfsSDQIiybvgSRQLlv27LUEUPqchBuA-2rp9Ed9G23m9lUYrLmunrba9EDnREe-1mRf_1cUIKCTAvTyX_SYRaDNzLXtDgupcYPw8FS5UZ4KdHi2tbPLD6Wxk_q9FeckrESglX0JAAUXZLpLk5mdlYwgXmTUu27gzIQ0I1tRY1t-nTHXreM7Fv2sHECGFFS5cn2aj5EIX8rbsmAcjnp79Wa8ARvkcCaUXfXVKSn2bAK2JDl0oQjJHC93-cr-5BdnFxd7nnSk Jun 02 19:43:48 volumio-allo volumio[967]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 02 19:43:48 volumio-allo volumio[967]: info: New Spotify access token = BQBfT1k40ma25oNCS6Nd_y9rKVaZbfsSDQIiybvgSRQLlv27LUEUPqchBuA-2rp9Ed9G23m9lUYrLmunrba9EDnREe-1mRf_1cUIKCTAvTyX_SYRaDNzLXtDgupcYPw8FS5UZ4KdHi2tbPLD6Wxk_q9FeckrESglX0JAAUXZLpLk5mdlYwgXmTUu27gzIQ0I1tRY1t-nTHXreM7Fv2sHECGFFS5cn2aj5EIX8rbsmAcjnp79Wa8ARvkcCaUXfXVKSn2bAK2JDl0oQjJHC93-cr-5BdnFxd7nnSk Jun 02 19:43:48 volumio-allo volumio[967]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 02 19:43:48 volumio-allo volumio[967]: info: Shairport-Sync Started Jun 02 19:43:48 volumio-allo volumio[967]: Error adding Membership: Error: addMembership EINVAL Jun 02 19:43:48 volumio-allo volumio[967]: info: Shairport-Sync Started Jun 02 19:43:48 volumio-allo volumio[967]: info: Shairport-Sync Started Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=info msg="running go-librespot 0.4.0" Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=debug msg="app state loaded" Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 02 19:43:48 volumio-allo volumio[967]: SPOTIFY: User informations: {"account_id":"bTPYrSty3u","country":"HU","display_name":"gemesgab","email":"gemesgab@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/gemesgab"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/gemesgab","id":"gemesgab","images":[],"product":"premium","type":"user","uri":"spotify:user:gemesgab"} Jun 02 19:43:48 volumio-allo volumio[967]: info: Spotify Successfully logged in Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 19:43:48 volumio-allo volumio[967]: info: [1780422228675] CoreMusicLibrary::Adding element Spotify Jun 02 19:43:48 volumio-allo volumio[967]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 19:43:48 volumio-allo volumio[967]: Cannot find translation for source YouTube2 Jun 02 19:43:48 volumio-allo volumio[967]: Cannot find translation for source YouTube Music Jun 02 19:43:48 volumio-allo volumio[967]: Cannot find translation for source Spotify Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 02 19:43:48 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:48+02:00" level=info msg="zeroconf server listening on port 44971" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="obtained new client token: AADF+abGRnfxDueqazJX4E+KLNnrNlqXz54EkL7QSgsI5yhdAw3VEFgxAgsIcT2XuPF1KG4VOvp74xz3XbLeoF7fuglQpsFHz366Qn6ATFMf9UAFv6ISjdmQFqi/BbwEWd2vy4O/3WswwZZ9PhLtTSd6VtUYu50M1Qmj5QxTYaUSCY4Ihei7vxcKgZLtR0kKK/yOnQqH7kTGY8M+XLyU9XmsJ57kBbtCeV2lMKEhcYGsCb9ANyFhkg==" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="completed keyexchange" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="completed challenge" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=info msg="authenticated AP" username="ge****ab" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=info msg="authenticated Login5" username="ge****ab" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="initializing zeroconf session" username="ge****ab" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="dealer connection opened" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=trace msg="starting accesspoint recv loop" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=trace msg="starting dealer recv loop" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=trace msg="received accesspoint ping" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="received connection id: ZmEyYjljYzgtNzIw...M0NDRjVERDQyNg==" Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=trace msg="received accesspoint pong ack" Jun 02 19:43:49 volumio-allo mpd[1264]: Jun 02 19:43 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 02 19:43:49 volumio-allo systemd[1]: Started Music Player Daemon. Jun 02 19:43:49 volumio-allo sudo[1246]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:49 volumio-allo sudo[1232]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:49 volumio-allo volumio[967]: info: Completed starting Core Plugins Jun 02 19:43:49 volumio-allo volumio[967]: info: ------------------------------------------- Jun 02 19:43:49 volumio-allo volumio[967]: info: ----- MyVolumio plugins startup ---- Jun 02 19:43:49 volumio-allo volumio[967]: info: ------------------------------------------- Jun 02 19:43:49 volumio-allo volumio[967]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 02 19:43:49 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:49+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 02 19:43:49 volumio-allo volumio[967]: info: MPD running with PID1264 Jun 02 19:43:49 volumio-allo volumio[967]: ,establishing connection Jun 02 19:43:49 volumio-allo volumio[967]: error: MPD error: The expression evaluated to a falsy value: Jun 02 19:43:49 volumio-allo volumio[967]: assert.ok(self.idling) Jun 02 19:43:49 volumio-allo volumio[967]: error: The expression evaluated to a falsy value: Jun 02 19:43:49 volumio-allo volumio[967]: assert.ok(self.idling) Jun 02 19:43:49 volumio-allo volumio[967]: error: MPD error: The expression evaluated to a falsy value: Jun 02 19:43:49 volumio-allo volumio[967]: assert.ok(self.idling) Jun 02 19:43:49 volumio-allo volumio[967]: error: The expression evaluated to a falsy value: Jun 02 19:43:49 volumio-allo volumio[967]: assert.ok(self.idling) Jun 02 19:43:49 volumio-allo volumio[967]: error: updateQueue error: null Jun 02 19:43:50 volumio-allo sudo[1360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 02 19:43:50 volumio-allo sudo[1360]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:50 volumio-allo sudo[1360]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:50 volumio-allo sudo[1363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 02 19:43:50 volumio-allo sudo[1363]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:50 volumio-allo sudo[1363]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:50 volumio-allo sudo[1366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 02 19:43:50 volumio-allo sudo[1366]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:50 volumio-allo systemd[1]: Started UPnP Renderer front-end to MPD. Jun 02 19:43:50 volumio-allo sudo[1366]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:50 volumio-allo volumio[967]: info: Upmpdcli Daemon Started Jun 02 19:43:50 volumio-allo volumio[1368]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 02 19:43:51 volumio-allo volumio[967]: info: go-librespot daemon successfully initialized Jun 02 19:43:51 volumio-allo volumio[1368]: .............++++ Jun 02 19:43:51 volumio-allo sudo[1385]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=2.1 //192.168.1.150/Adat1TB /mnt/NAS/Adat1TB Jun 02 19:43:51 volumio-allo sudo[1385]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:51 volumio-allo kernel: CIFS: Attempting to mount //192.168.1.150/Adat1TB Jun 02 19:43:51 volumio-allo sudo[1388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Gabor,password=xerxes,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.150/Adat /mnt/NAS/Adat Jun 02 19:43:51 volumio-allo sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 19:43:51 volumio-allo sudo[1385]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:51 volumio-allo kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Jun 02 19:43:51 volumio-allo kernel: CIFS: Attempting to mount //192.168.1.150/Adat Jun 02 19:43:51 volumio-allo volumio[967]: info: Cannot mount NAS Adat1TB at system boot, trial number 2 ,retrying in 5 seconds Jun 02 19:43:51 volumio-allo sudo[1388]: pam_unix(sudo:session): session closed for user root Jun 02 19:43:51 volumio-allo volumio[967]: info: Cannot mount NAS Adat at system boot, trial number 2 ,retrying in 5 seconds Jun 02 19:43:51 volumio-allo kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Jun 02 19:43:51 volumio-allo kernel: CIFS: VFS: \\192.168.1.150 Send error in SessSetup = -13 Jun 02 19:43:51 volumio-allo kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Jun 02 19:43:54 volumio-allo volumio[967]: info: Initializing connection to go-librespot Websocket Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="new websocket client" Jun 02 19:43:54 volumio-allo volumio[967]: info: Connection to go-librespot Websocket established Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="handling transfer player command from 5c8fbb009c22f17ef77fbe068f94d69d1228cb89" Jun 02 19:43:54 volumio-allo volumio[967]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="resolved context of track" uri="spotify:user:gemesgab:collection" Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=trace msg="fetched new page 0 with 629 items (list: 629)" uri="spotify:user:gemesgab:collection" Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="loading track (paused: true, position: 20012ms)" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=trace msg="emitting websocket event: will_play" Jun 02 19:43:54 volumio-allo volumio[967]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:2xyBtmSADfdGSkiZgbTQhj","play_origin":"playlist"}} Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1231" Jun 02 19:43:54 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:54+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="selected format OGG_VORBIS_320 (b1902df87b01e0aaece8a289e09562e1b1e07de7)" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="requested aes key for file b1902df87b01e0aaece8a289e09562e1b1e07de7, gid: 2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo volumio-remote-updater[549]: [2026-06-02 19:43:55] [connect] Successful connection Jun 02 19:43:55 volumio-allo volumio-remote-updater[549]: [2026-06-02 19:43:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1780422235 101 Jun 02 19:43:55 volumio-allo volumio[967]: 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: 3 Jun 02 19:43:55 volumio-allo volumio[1368]: ...........................................++++ Jun 02 19:43:55 volumio-allo volumio[1368]: e is 65537 (0x010001) Jun 02 19:43:55 volumio-allo volumio[1368]: writing RSA key Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="fetched first chunk of 9, total size is 4481216 bytes" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="fetched chunk 3/8, size: 524288" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="fetched chunk 2/8, size: 524288" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="fetched chunk 4/8, size: 524288" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=trace msg="seek to 20012ms (diff: 103ms, samples: 882529, bytes: 670645)" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="created new output device" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=info msg="loaded track \"The Eiger Sanction Theme\" (paused: true, position: 20012ms, duration: 132653ms, prefetched: false)" uri="spotify:track:2xyBtmSADfdGSkiZgbTQhj" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=trace msg="emitting websocket event: metadata" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=trace msg="emitting websocket event: active" Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="sending successful reply for dealer request" Jun 02 19:43:55 volumio-allo volumio[967]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2xyBtmSADfdGSkiZgbTQhj","name":"The Eiger Sanction Theme","artist_names":["Taxim Trio"],"album_name":"Cafe de Beyoğlu Story (I-Ii-Iii-Iiii)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b112e6d9e26024bd5afc8fbc","position":20012,"duration":132653,"release_date":"year:2016 month:1 day:19","track_number":7,"disc_number":3}} Jun 02 19:43:55 volumio-allo volumio[967]: SPOTIFY: received: {"type":"active","data":null} Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 02 19:43:55 volumio-allo volumio[967]: info: Aligning Spotify Volume to Volumio Volume Jun 02 19:43:55 volumio-allo volumio[967]: info: CoreCommandRouter::volumioGetState Jun 02 19:43:55 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:55+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 02 19:43:55 volumio-allo volumio[967]: info: CorePlayQueue::getTrack 0 Jun 02 19:43:55 volumio-allo volumio[967]: info: Setting Spotify Volume from Volumio: 67 Jun 02 19:43:56 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 19:43:56 volumio-allo go-librespot[1310]: time="2026-06-02T19:43:56+02:00" level=trace msg="emitting websocket event: paused" Jun 02 19:43:56 volumio-allo volumio[967]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:2xyBtmSADfdGSkiZgbTQhj","play_origin":"playlist"}} Jun 02 19:43:56 volumio-allo volumio[967]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 19:43:56 volumio-allo volumio[967]: TypeError: Cannot read property 'service' of undefined Jun 02 19:43:56 volumio-allo volumio[967]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Jun 02 19:43:56 volumio-allo volumio[967]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Jun 02 19:43:56 volumio-allo volumio[967]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Jun 02 19:43:56 volumio-allo volumio[967]: at WebSocket.emit (events.js:315:20) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.emit (events.js:315:20) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 02 19:43:56 volumio-allo volumio[967]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 02 19:43:56 volumio-allo volumio[967]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 02 19:43:56 volumio-allo volumio[967]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 02 19:43:56 volumio-allo volumio[967]: at Socket.emit (events.js:315:20) Jun 02 19:43:56 volumio-allo volumio[967]: at addChunk (internal/streams/readable.js:309:12) Jun 02 19:43:56 volumio-allo volumio[967]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 02 19:43:56 volumio-allo volumio[967]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 19:43:56 volumio-allo sudo[1422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-06-02 19:42 Jun 02 19:43:56 volumio-allo sudo[1422]: 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"