Feb 27 07:21:00 volumio ntpd[996]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Feb 27 07:21:00 volumio ntpd[996]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Feb 27 07:21:00 volumio ntpd[996]: DNS: Pool taking: 129.70.132.32 Feb 27 07:21:00 volumio ntpd[996]: DNS: Pool taking: 77.90.40.94 Feb 27 07:21:00 volumio ntpd[996]: DNS: Pool taking: 176.9.157.155 Feb 27 07:21:00 volumio ntpd[996]: DNS: Pool taking: 85.215.166.214 Feb 27 07:21:00 volumio ntpd[996]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "network"... Feb 27 07:21:00 volumio volumio[1199]: info: Refreshing Cached IP Addresses Feb 27 07:21:00 volumio sudo[1369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 07:21:00 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:00 volumio sudo[1368]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 27 07:21:00 volumio sudo[1368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:00 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:00 volumio sudo[1368]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "services"... Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "volumio5onboarding"... Feb 27 07:21:00 volumio sudo[1378]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 27 07:21:00 volumio sudo[1378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "alsa_controller"... Feb 27 07:21:00 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "wizard"... Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "networkfs"... Feb 27 07:21:00 volumio volumio[1199]: info: Starting Udev Watcher for removable devices Feb 27 07:21:00 volumio sudo[1401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=buster,password=Dummheit13,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.5/multimedia\\Musik /mnt/NAS/TrueNAS Feb 27 07:21:00 volumio sudo[1401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:00 volumio volumio[1199]: info: Ignoring mount for partition: boot Feb 27 07:21:00 volumio volumio[1199]: info: Ignoring mount for partition: volumio Feb 27 07:21:00 volumio volumio[1199]: info: Ignoring mount for partition: volumio_data Feb 27 07:21:00 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "volumio_command_line_client"... Feb 27 07:21:00 volumio volumio[1199]: info: Plugin upnp is not enabled Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "my_music"... Feb 27 07:21:00 volumio volumio[1199]: info: Loading plugin "mpd"... Feb 27 07:21:01 volumio kernel: netfs: FS-Cache loaded Feb 27 07:21:01 volumio kernel: Key type cifs.spnego registered Feb 27 07:21:01 volumio kernel: Key type cifs.idmap registered Feb 27 07:21:01 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Feb 27 07:21:01 volumio kernel: CIFS: Attempting to mount //192.168.1.5/multimedia/Musik Feb 27 07:21:01 volumio volumio-remote-updater[780]: [2026-02-27 07:21:01] [connect] Successful connection Feb 27 07:21:01 volumio volumio[1199]: info: Plugin upnp_browser is not enabled Feb 27 07:21:01 volumio volumio[1199]: info: Loading plugin "alarm-clock"... Feb 27 07:21:01 volumio volumio[1199]: info: Loading plugin "airplay_emulation"... Feb 27 07:21:01 volumio volumio[1199]: info: Starting Shairport Sync Feb 27 07:21:01 volumio volumio[1199]: info: Loading plugin "last_100"... Feb 27 07:21:01 volumio volumio[1199]: info: Loading plugin "webradio"... Feb 27 07:21:01 volumio sudo[1401]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:03 volumio volumio[1199]: info: Loading plugin "i2s_dacs"... Feb 27 07:21:03 volumio volumio[1199]: info: I2S DAC not set, start Auto-detection Feb 27 07:21:03 volumio volumio[1199]: info: Loading plugin "volumiodiscovery"... Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** For more information see Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:21:03 volumio volumio[1199]: *** WARNING *** For more information see Feb 27 07:21:03 volumio node[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 07:21:03 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:21:03 volumio node[1199]: *** WARNING *** For more information see Feb 27 07:21:03 volumio node[1199]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 07:21:03 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 07:21:03 volumio node[1199]: *** WARNING *** For more information see Feb 27 07:21:32 volumio ntpd[996]: CLOCK: time stepped by 29.758126 Feb 27 07:21:32 volumio ntpd[996]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Feb 27 07:21:32 volumio volumio[1199]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 27 07:21:32 volumio volumio[1199]: info: Discovery: Started advertising with name: Volumio Feb 27 07:21:32 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 07:21:32 volumio volumio[1199]: info: Loading plugin "spop"... Feb 27 07:21:34 volumio sudo[1378]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "outputs"... Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "albumart"... Feb 27 07:21:34 volumio volumio[1199]: info: Plugin example_plugin is not enabled Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "inputs"... Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "updater_comm"... Feb 27 07:21:34 volumio volumio[1199]: info: Plugin mpdemulation is not enabled Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "rest_api"... Feb 27 07:21:34 volumio volumio[1199]: info: Loading plugin "websocket"... Feb 27 07:21:34 volumio volumio[1199]: info: Starting Socket.io Server version 1.7.4 Feb 27 07:21:34 volumio volumio[1199]: info: Loading i18n strings for locale de Feb 27 07:21:34 volumio volumio[1199]: Updating browse sources language Feb 27 07:21:34 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::initPlayerControls Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: Express server listening on port 3000 Feb 27 07:21:35 volumio volumio[1199]: [Metrics] WebUI: 9s 865.46ms Feb 27 07:21:35 volumio volumio[1199]: info: CoreStateMachine::resetVolumioState Feb 27 07:21:35 volumio volumio[1199]: info: CoreStateMachine::getcurrentVolume Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 07:21:35 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:35 volumio volumio[1199]: info: Volumio Network Manager: Network status updated: 2 Feb 27 07:21:35 volumio volumio[1441]: Forking 3 albumart workers Feb 27 07:21:35 volumio volumio-remote-updater[780]: [2026-02-27 07:21:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772173261 101 Feb 27 07:21:35 volumio volumio[1199]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 27 07:21:35 volumio volumio[1199]: Unable to parse: Feb 27 07:21:35 volumio volumio[1199]: Simple mixer control 'PCM',0 Feb 27 07:21:35 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Feb 27 07:21:35 volumio volumio[1199]: Playback channels: Mono Feb 27 07:21:35 volumio volumio[1199]: Mono: Playback [on] Feb 27 07:21:35 volumio volumio[1199]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Feb 27 07:21:36 volumio volumio[1199]: info: Reloading queue from file Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:36 volumio volumio[1199]: Unable to parse: Feb 27 07:21:36 volumio volumio[1199]: Simple mixer control 'PCM',0 Feb 27 07:21:36 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Feb 27 07:21:36 volumio volumio[1199]: Playback channels: Mono Feb 27 07:21:36 volumio volumio[1199]: Mono: Playback [on] Feb 27 07:21:36 volumio volumio[1199]: info: VolumeController:: Volume=undefined Mute =false Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::pushState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::updateTrackBlock Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrackBlock Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::setRepeat true single undefined Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::pushState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::setRandom undefined Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::pushState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Feb 27 07:21:36 volumio volumio[1199]: info: Setting Device type: Raspberry PI Feb 27 07:21:36 volumio volumio[1199]: Unable to parse: Feb 27 07:21:36 volumio volumio[1199]: Simple mixer control 'PCM',0 Feb 27 07:21:36 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Feb 27 07:21:36 volumio volumio[1199]: Playback channels: Mono Feb 27 07:21:36 volumio volumio[1199]: Mono: Playback [on] Feb 27 07:21:36 volumio volumio[1199]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Feb 27 07:21:36 volumio volumio[1199]: info: Listing playlists Feb 27 07:21:36 volumio volumio[1199]: info: Listing playlists Feb 27 07:21:36 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Feb 27 07:21:36 volumio volumio[1199]: Unable to parse: Feb 27 07:21:36 volumio volumio[1199]: Simple mixer control 'PCM',0 Feb 27 07:21:36 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Feb 27 07:21:36 volumio volumio[1199]: Playback channels: Mono Feb 27 07:21:36 volumio volumio[1199]: Mono: Playback [on] Feb 27 07:21:36 volumio volumio[1199]: info: VolumeController:: Volume=undefined Mute =false Feb 27 07:21:36 volumio volumio[1199]: info: CoreStateMachine::pushState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Feb 27 07:21:36 volumio volumio[1199]: info: Discovery: adding 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Feb 27 07:21:36 volumio volumio[1199]: info: Discovery: Found device Volumio Feb 27 07:21:36 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:36 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:37 volumio volumio[1199]: info: Discovery: this is already registered, 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Feb 27 07:21:37 volumio volumio[1199]: info: Discovery: Found device Volumio Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:37 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:37 volumio volumio[1199]: info: Completed loading Core Plugins Feb 27 07:21:37 volumio volumio[1199]: info: Preparing to generate the ALSA configuration file Feb 27 07:21:37 volumio volumio[1199]: info: Asound.conf file unchanged, so no further update is needed Feb 27 07:21:37 volumio volumio[1199]: info: Output device has changed, restarting MPD Feb 27 07:21:37 volumio dhcpcd[668]: timed out Feb 27 07:21:37 volumio sh[642]: timed out Feb 27 07:21:37 volumio dhcpcd[668]: dhcpcd exited Feb 27 07:21:37 volumio sh[642]: dhcpcd exited Feb 27 07:21:37 volumio sh[584]: ifup: failed to bring up eth0 Feb 27 07:21:37 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:21:37 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 27 07:21:37 volumio volumio[1199]: info: Output device has changed, restarting Shairport Sync Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:37 volumio sudo[1499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 07:21:37 volumio sudo[1499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:37 volumio sudo[1502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 07:21:37 volumio sudo[1502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:37 volumio sudo[1499]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:37 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:21:37 volumio volumio[1199]: info: ___________ START PLUGINS ___________ Feb 27 07:21:37 volumio volumio[1199]: info: ControllerMpd::onStart: Initializing MPD Feb 27 07:21:37 volumio volumio[1199]: info: Creating MPD Configuration file Feb 27 07:21:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 27 07:21:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 27 07:21:37 volumio sudo[1511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 27 07:21:37 volumio sudo[1511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:37 volumio sudo[1513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 07:21:37 volumio sudo[1514]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 07:21:37 volumio sudo[1513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:37 volumio sudo[1514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 27 07:21:37 volumio sudo[1520]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 27 07:21:37 volumio sudo[1514]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:37 volumio sudo[1517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 07:21:37 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:37 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:37 volumio sudo[1517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:38 volumio sudo[1513]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:38 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 27 07:21:38 volumio sudo[1511]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:38 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 27 07:21:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 27 07:21:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 27 07:21:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 27 07:21:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 27 07:21:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 27 07:21:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 27 07:21:38 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:21:38 volumio volumio[1199]: info: [1772173298187] CoreMusicLibrary::Adding element Last_100 Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:21:38 volumio volumio[1199]: info: [1772173298191] CoreMusicLibrary::Adding element Webradio Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:21:38 volumio sudo[1532]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 07:21:38 volumio sudo[1532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 27 07:21:38 volumio sudo[1538]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 27 07:21:38 volumio sudo[1532]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:21:38 volumio volumio[1199]: info: Initializing BBC Radios Feb 27 07:21:38 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:38.485+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:38 volumio volumio[1199]: info: Creating Spotify config file Feb 27 07:21:38 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:39 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Feb 27 07:21:39 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:21:39 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:21:39 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Feb 27 07:21:39 volumio upmpdcli[1556]: Could not open config: /tmp/upmpdcli.conf Feb 27 07:21:39 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:21:39 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 27 07:21:40 volumio volumio[1199]: info: Volumio Calling Home Feb 27 07:21:41 volumio volumio[1199]: info: MPD Permissions set Feb 27 07:21:41 volumio volumio[1199]: info: MPD Permissions set Feb 27 07:21:41 volumio volumio[1199]: 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: 2 Feb 27 07:21:41 volumio volumio[1199]: 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: 2 Feb 27 07:21:41 volumio volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 27 07:21:41 volumio volumio[1199]: info: Volumio called home Feb 27 07:21:41 volumio volumio[1199]: info: Received Get System Info Feb 27 07:21:41 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 27 07:21:41 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 27 07:21:41 volumio volumio[1199]: info: Discovery: Getting this device information Feb 27 07:21:41 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:41 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:41 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 27 07:21:41 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:41.711+01:00 level=INFO msg="system info for 92ee4819b6d983ad01a2a5761e1ddbd1" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 27 07:21:41 volumio volumio[1456]: Starting albumart workers Feb 27 07:21:41 volumio volumio[1455]: Starting albumart workers Feb 27 07:21:42 volumio volumio[1199]: info: Received Get System Info Feb 27 07:21:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 27 07:21:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 27 07:21:42 volumio volumio[1199]: info: Discovery: Getting this device information Feb 27 07:21:42 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:42 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 27 07:21:42 volumio mpd[1539]: 2026-02-27T07:21:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 27 07:21:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 27 07:21:42 volumio sudo[1502]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:42 volumio sudo[1517]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:42 volumio volumio[1457]: Starting albumart workers Feb 27 07:21:43 volumio volumio[1199]: info: Spotify config file written Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 27 07:21:43 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:43.264+01:00 level=INFO msg="enabling local network discovery" Feb 27 07:21:43 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:43.307+01:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 27 07:21:43 volumio sudo[1585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 27 07:21:43 volumio sudo[1585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 27 07:21:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 27 07:21:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 27 07:21:43 volumio go-librespot[1590]: go-librespot daemon starting... Feb 27 07:21:43 volumio sudo[1585]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:21:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:21:43 volumio go-librespot[1595]: time="2026-02-27T07:21:43+01:00" level=info msg="running go-librespot 0.4.0" Feb 27 07:21:43 volumio go-librespot[1595]: time="2026-02-27T07:21:43+01:00" level=debug msg="app state loaded" Feb 27 07:21:43 volumio go-librespot[1595]: time="2026-02-27T07:21:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 07:21:43 volumio volumio[1199]: info: No need to fix Spotify hosts Feb 27 07:21:43 volumio volumio[1199]: info: Completed starting Core Plugins Feb 27 07:21:43 volumio volumio[1199]: info: ------------------------------------------- Feb 27 07:21:43 volumio volumio[1199]: info: ----- MyVolumio plugins startup ---- Feb 27 07:21:43 volumio volumio[1199]: info: ------------------------------------------- Feb 27 07:21:43 volumio volumio[1199]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 27 07:21:44 volumio volumio[1199]: info: Received Get System Info Feb 27 07:21:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 27 07:21:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 27 07:21:44 volumio volumio[1199]: info: Discovery: Getting this device information Feb 27 07:21:44 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:44 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=info msg="zeroconf server listening on port 45055" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="obtained new client token: AAAdm2Bi5dK4yQr8cSjv1a8o2wTqmrsGuDX0T8KMdZMGdyWO/uzEUwtAA5nJm4gVIDttecpa2Soy3Z5X2OVRF8VMnS75+cgufagmrflcybz2vS3XPsn0PRW3MYcHRiDe+qLOUHGN1yDh9zVxnE45shkENIaV6Gn+df6C4zEK/jfmizvpIdSXJVYD0U5BlSnM+jgok5xrKFk9KA3RxdZ9fO4ipyBe3YNV2INRJPMEA0cJEjLc8yHzAkU=" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="completed keyexchange" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="completed challenge" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=info msg="authenticated AP" username="bu********pf" Feb 27 07:21:44 volumio volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 07:21:44 volumio volumio[1199]: SPOTIFY: BQBlITWy1Y7995jKE6T-0EjN2nJOxDeG7j7yE7PeLwzBA6p_KI7q0T0TtauMI14R50RZWkItyyex7OsH8FgUhFUBsSMP2EJCFfZF8AlTHaW7aV3pUhALZj_F0u9ylPDWX2VR4rFDfEIyXMF7Zk-e5NYnRbE6QUYatJZ14MUHlsbbKOyQ_i_azCqM11Gmr3kbcIWVEZd7n4FNt2bLHyGuM0TcLA_9vuFKP6gUmjLeDNJD5Lp3MSbioH2mQi97nsGO9g4hRKRCrO9zl_AhhY8D7ogppNegdtBkBPvcLhE Feb 27 07:21:44 volumio volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 07:21:44 volumio volumio[1199]: info: New Spotify access token = BQBlITWy1Y7995jKE6T-0EjN2nJOxDeG7j7yE7PeLwzBA6p_KI7q0T0TtauMI14R50RZWkItyyex7OsH8FgUhFUBsSMP2EJCFfZF8AlTHaW7aV3pUhALZj_F0u9ylPDWX2VR4rFDfEIyXMF7Zk-e5NYnRbE6QUYatJZ14MUHlsbbKOyQ_i_azCqM11Gmr3kbcIWVEZd7n4FNt2bLHyGuM0TcLA_9vuFKP6gUmjLeDNJD5Lp3MSbioH2mQi97nsGO9g4hRKRCrO9zl_AhhY8D7ogppNegdtBkBPvcLhE Feb 27 07:21:44 volumio volumio[1199]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=info msg="authenticated Login5" username="bu********pf" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="initializing zeroconf session" username="bu********pf" Feb 27 07:21:44 volumio volumio[1199]: info: MPD running with PID1539 Feb 27 07:21:44 volumio volumio[1199]: ,establishing connection Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="dealer connection opened" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=trace msg="starting accesspoint recv loop" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=trace msg="starting dealer recv loop" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=trace msg="received accesspoint ping" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="received connection id: YzZlYzMxNDgtNmZj...OTRGRjM5Qzk3NQ==" Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=trace msg="received accesspoint pong ack" Feb 27 07:21:44 volumio volumio-remote-updater[780]: Test mode disabled Feb 27 07:21:44 volumio volumio-remote-updater[780]: Alpha mode disabled Feb 27 07:21:44 volumio volumio-remote-updater[780]: Alpha legacy test mode disabled Feb 27 07:21:44 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:44 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:44 volumio go-librespot[1595]: time="2026-02-27T07:21:44+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 27 07:21:45 volumio volumio[1199]: error: MPD error: The expression evaluated to a falsy value: Feb 27 07:21:45 volumio volumio[1199]: assert.ok(self.idling) Feb 27 07:21:45 volumio volumio[1199]: error: The expression evaluated to a falsy value: Feb 27 07:21:45 volumio volumio[1199]: assert.ok(self.idling) Feb 27 07:21:45 volumio volumio[1199]: error: MPD error: The expression evaluated to a falsy value: Feb 27 07:21:45 volumio volumio[1199]: assert.ok(self.idling) Feb 27 07:21:45 volumio volumio[1199]: error: The expression evaluated to a falsy value: Feb 27 07:21:45 volumio volumio[1199]: assert.ok(self.idling) Feb 27 07:21:45 volumio volumio[1199]: info: Starting Shairport Sync Feb 27 07:21:45 volumio volumio[1199]: info: Starting Shairport Sync Feb 27 07:21:45 volumio volumio[1199]: info: Starting Shairport Sync Feb 27 07:21:45 volumio volumio[1199]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 27 07:21:45 volumio sudo[1633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:21:45 volumio sudo[1631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:21:45 volumio sudo[1631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:45 volumio sudo[1633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:45 volumio volumio[1199]: error: updateQueue error: null Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 27 07:21:45 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:45.268+01: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" Feb 27 07:21:45 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:45.269+01: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" Feb 27 07:21:45 volumio volumio5-onboarding[1527]: time=2026-02-27T07:21:45.269+01: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" Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:45 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:21:45 volumio sudo[1635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 07:21:45 volumio sudo[1635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:21:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 27 07:21:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 27 07:21:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:21:45 volumio systemd[1]: shairport-sync.service: Consumed 1.162s CPU time. Feb 27 07:21:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 27 07:21:45 volumio sudo[1631]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:45 volumio sudo[1635]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:45 volumio volumio[1199]: info: Shairport-Sync Started Feb 27 07:21:45 volumio volumio[1199]: Error adding Membership: Error: addMembership EINVAL Feb 27 07:21:45 volumio volumio[1199]: info: Shairport-Sync Started Feb 27 07:21:45 volumio sudo[1633]: pam_unix(sudo:session): session closed for user root Feb 27 07:21:45 volumio volumio[1199]: SPOTIFY: User informations: {"country":"DE","display_name":"bustertrumpf","email":"nico@raecher-der-enterbten.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/bustertrumpf"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/bustertrumpf","id":"bustertrumpf","images":[],"product":"premium","type":"user","uri":"spotify:user:bustertrumpf"} Feb 27 07:21:45 volumio volumio[1199]: info: Spotify Successfully logged in Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 07:21:45 volumio volumio[1199]: info: [1772173305448] CoreMusicLibrary::Adding element Spotify Feb 27 07:21:45 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 07:21:45 volumio volumio[1199]: Cannot find translation for source Spotify Feb 27 07:21:45 volumio volumio[1199]: info: Shairport-Sync Started Feb 27 07:21:47 volumio volumio[1199]: info: go-librespot daemon successfully initialized Feb 27 07:21:50 volumio volumio[1199]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 27 07:21:52 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 27 07:21:52 volumio volumio[1199]: info: Initializing connection to go-librespot Websocket Feb 27 07:21:54 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Feb 27 07:21:54 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:21:54 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:21:54 volumio upmpdcli[1684]: Could not open config: /tmp/upmpdcli.conf Feb 27 07:21:54 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:21:54 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 27 07:21:55 volumio go-librespot[1595]: time="2026-02-27T07:21:55+01:00" level=debug msg="new websocket client" Feb 27 07:21:55 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 27 07:21:55 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 27 07:21:55 volumio volumio[1199]: info: Connection to go-librespot Websocket established Feb 27 07:21:56 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Feb 27 07:21:56 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Feb 27 07:22:00 volumio volumio[1199]: info: Listing playlists Feb 27 07:22:00 volumio volumio[1199]: info: Listing playlists Feb 27 07:22:00 volumio volumio[1199]: info: Getting Spotify volume Feb 27 07:22:08 volumio volumio[1199]: error: MyVolumio Plugin failed to start in a timely fashion Feb 27 07:22:08 volumio volumio[1199]: [Metrics] CommandRouter: 40s 961.56ms Feb 27 07:22:08 volumio volumio[1199]: info: CoreCommandRouter::volumiosetStartupVolume Feb 27 07:22:08 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 07:22:08 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:22:08 volumio volumio[1199]: info: CoreCommandRouter::Close All Modals sent Feb 27 07:22:08 volumio volumio[1199]: info: CoreCommandRouter::Close All Modals sent Feb 27 07:22:09 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Feb 27 07:22:09 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:22:09 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 27 07:22:09 volumio upmpdcli[1710]: Could not open config: /tmp/upmpdcli.conf Feb 27 07:22:09 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 27 07:22:09 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 27 07:22:13 volumio volumio[1199]: info: Spotify volume: 100 Feb 27 07:22:13 volumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 1 Feb 27 07:22:13 volumio kernel: xhci_hcd 0000:01:00.0: @000000041cd06060 00000000 00000000 0e000000 02028000 Feb 27 07:22:13 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 27 07:22:14 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 27 07:22:14 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 27 07:22:14 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 07:22:14 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:22:14 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 27 07:22:14 volumio go-librespot[1595]: time="2026-02-27T07:22:14+01:00" level=trace msg="sent dealer ping" Feb 27 07:22:14 volumio go-librespot[1595]: time="2026-02-27T07:22:14+01:00" level=trace msg="received dealer pong" Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin bluetooth to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin multiroom to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin metavolumio to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin cd_controller to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 27 07:22:15 volumio volumio[1199]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 27 07:22:18 volumio volumio[1199]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 27 07:22:18 volumio volumio[1199]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 27 07:22:18 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:22:18 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 07:22:18 volumio volumio[1199]: info: Starting MyVolumio Remote Streaming Endpoints Feb 27 07:22:18 volumio volumio[1199]: info: MyVolumio login type: Token Feb 27 07:22:18 volumio volumio[1199]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 27 07:22:18 volumio volumio[1199]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 27 07:22:20 volumio volumio[1199]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 27 07:22:20 volumio volumio[1199]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 27 07:22:20 volumio volumio[1199]: info: Streaming services startup Feb 27 07:22:20 volumio volumio[1199]: info: Starting Streaming Daemon Feb 27 07:22:20 volumio volumio[1199]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 27 07:22:21 volumio sudo[1733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 27 07:22:21 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 27 07:22:21 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root Feb 27 07:22:21 volumio volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 27 07:22:21 volumio volumio[1199]: info: BOOT COMPLETED Feb 27 07:22:21 volumio volumio[1199]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 07:22:21 volumio volumio[1199]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Feb 27 07:22:21 volumio volumio[1199]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Feb 27 07:22:21 volumio volumio[1199]: at new NodeError (node:internal/errors:405:5) Feb 27 07:22:21 volumio volumio[1199]: at assert (node:internal/assert:14:11) Feb 27 07:22:21 volumio volumio[1199]: at internalConnectMultiple (node:net:1118:3) Feb 27 07:22:21 volumio volumio[1199]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Feb 27 07:22:21 volumio volumio[1199]: at listOnTimeout (node:internal/timers:575:11) Feb 27 07:22:21 volumio volumio[1199]: at process.processTimers (node:internal/timers:514:7) { Feb 27 07:22:21 volumio volumio[1199]: code: 'ERR_INTERNAL_ASSERTION' Feb 27 07:22:21 volumio volumio[1199]: } Feb 27 07:22:21 volumio volumio[1199]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 07:22:24 volumio sudo[1766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-27 07:21' Feb 27 07:22:24 volumio sudo[1766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"