Jan 12 12:45:00 volumio volumio[1205]: info: Loading plugin "network"... Jan 12 12:45:00 volumio volumio[1205]: info: Refreshing Cached IP Addresses Jan 12 12:45:00 volumio sudo[1288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 12:45:00 volumio sudo[1288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:00 volumio volumio[1205]: info: Loading plugin "services"... Jan 12 12:45:00 volumio volumio[1205]: info: Loading plugin "alsa_controller"... Jan 12 12:45:00 volumio sudo[1288]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:00 volumio sudo[1285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 12:45:00 volumio sudo[1285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:00 volumio sudo[1285]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:00 volumio sudo[1294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 12 12:45:00 volumio sudo[1294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:01 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "wizard"... Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "networkfs"... Jan 12 12:45:01 volumio volumio[1205]: info: Starting Udev Watcher for removable devices Jan 12 12:45:01 volumio sudo[1320]: 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 Jan 12 12:45:01 volumio sudo[1320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:01 volumio volumio[1205]: info: Ignoring mount for partition: boot Jan 12 12:45:01 volumio volumio[1205]: info: Ignoring mount for partition: volumio Jan 12 12:45:01 volumio volumio[1205]: info: Ignoring mount for partition: volumio_data Jan 12 12:45:01 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "volumio_command_line_client"... Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "upnp"... Jan 12 12:45:01 volumio volumio[1205]: info: [1768218301435] Starting Upmpd Daemon Jan 12 12:45:01 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "my_music"... Jan 12 12:45:01 volumio kernel: netfs: FS-Cache loaded Jan 12 12:45:01 volumio volumio[1205]: info: Loading plugin "mpd"... Jan 12 12:45:01 volumio kernel: Key type cifs.spnego registered Jan 12 12:45:01 volumio kernel: Key type cifs.idmap registered Jan 12 12:45: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. Jan 12 12:45:01 volumio kernel: CIFS: Attempting to mount //192.168.1.5/multimedia/Musik Jan 12 12:45:01 volumio sudo[1294]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:01 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jan 12 12:45:01 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jan 12 12:45:01 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Jan 12 12:45:02 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jan 12 12:45:02 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jan 12 12:45:02 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jan 12 12:45:02 volumio sudo[1320]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:02 volumio dhcpcd[647]: timed out Jan 12 12:45:02 volumio sh[642]: timed out Jan 12 12:45:02 volumio sh[610]: ifup: failed to bring up eth0 Jan 12 12:45:02 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 12 12:45:02 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 12 12:45:02 volumio volumio[1205]: info: Loading plugin "upnp_browser"... Jan 12 12:45:05 volumio volumio[1205]: info: Starting UPNP Browser Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "alarm-clock"... Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "airplay_emulation"... Jan 12 12:45:05 volumio volumio[1205]: info: Starting Shairport Sync Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "last_100"... Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "webradio"... Jan 12 12:45:05 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Jan 12 12:45:05 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "i2s_dacs"... Jan 12 12:45:05 volumio volumio[1205]: info: I2S DAC not set, start Auto-detection Jan 12 12:45:05 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 12:45:05 volumio volumio[1205]: info: Loading plugin "volumiodiscovery"... Jan 12 12:45:05 volumio upmpdcli[1369]: Could not open config: /tmp/upmpdcli.conf Jan 12 12:45:05 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 12:45:05 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** For more information see Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 12:45:06 volumio volumio[1205]: *** WARNING *** For more information see Jan 12 12:45:06 volumio node[1205]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 12:45:06 volumio node[1205]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 12:45:06 volumio node[1205]: *** WARNING *** For more information see Jan 12 12:45:06 volumio node[1205]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 12:45:06 volumio node[1205]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 12:45:06 volumio node[1205]: *** WARNING *** For more information see Jan 12 12:45:06 volumio volumio[1205]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 12 12:45:06 volumio volumio[1205]: info: Discovery: Started advertising with name: Volumio Jan 12 12:45:06 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 12:45:06 volumio volumio[1205]: info: Loading plugin "spop"... Jan 12 12:45:07 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jan 12 12:45:09 volumio volumio[1205]: info: Loading plugin "outputs"... Jan 12 12:45:09 volumio volumio[1205]: info: Loading plugin "albumart"... Jan 12 12:45:09 volumio volumio[1205]: info: Plugin example_plugin is not enabled Jan 12 12:45:09 volumio volumio[1205]: info: Loading plugin "inputs"... Jan 12 12:45:09 volumio volumio[1205]: info: Loading plugin "updater_comm"... Jan 12 12:45:09 volumio volumio[1205]: info: Plugin mpdemulation is not enabled Jan 12 12:45:09 volumio volumio[1205]: info: Loading plugin "rest_api"... Jan 12 12:45:10 volumio volumio[1205]: info: Loading plugin "websocket"... Jan 12 12:45:10 volumio volumio[1205]: info: Starting Socket.io Server version 1.7.4 Jan 12 12:45:10 volumio volumio[1205]: info: Loading i18n strings for locale de Jan 12 12:45:10 volumio volumio[1205]: Updating browse sources language Jan 12 12:45:10 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::initPlayerControls Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: Express server listening on port 3000 Jan 12 12:45:11 volumio volumio[1205]: [Metrics] WebUI: 15s 818.03ms Jan 12 12:45:11 volumio volumio[1205]: info: CoreStateMachine::resetVolumioState Jan 12 12:45:11 volumio volumio[1205]: info: CoreStateMachine::getcurrentVolume Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 12:45:11 volumio volumio[1376]: Forking 3 albumart workers Jan 12 12:45:11 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:11 volumio volumio[1205]: info: Volumio Network Manager: Network status updated: 2 Jan 12 12:45:11 volumio sudo[1432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 12:45:11 volumio sudo[1432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:12 volumio sudo[1432]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:12 volumio sudo[1434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 12:45:12 volumio sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:12 volumio sudo[1434]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:12 volumio volumio-remote-updater[716]: [2026-01-12 12:45:12] [connect] Successful connection Jan 12 12:45:12 volumio volumio[1205]: Unable to parse: Jan 12 12:45:12 volumio volumio[1205]: Simple mixer control 'PCM',0 Jan 12 12:45:12 volumio volumio[1205]: Capabilities: pswitch pswitch-joined Jan 12 12:45:12 volumio volumio[1205]: Playback channels: Mono Jan 12 12:45:12 volumio volumio[1205]: Mono: Playback [on] Jan 12 12:45:12 volumio volumio[1205]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Jan 12 12:45:13 volumio volumio[1205]: info: Reloading queue from file Jan 12 12:45:13 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:13 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:13 volumio volumio-remote-updater[716]: [2026-01-12 12:45:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768218312 101 Jan 12 12:45:13 volumio volumio[1205]: 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 Jan 12 12:45:13 volumio volumio[1205]: Unable to parse: Jan 12 12:45:13 volumio volumio[1205]: Simple mixer control 'PCM',0 Jan 12 12:45:13 volumio volumio[1205]: Capabilities: pswitch pswitch-joined Jan 12 12:45:13 volumio volumio[1205]: Playback channels: Mono Jan 12 12:45:13 volumio volumio[1205]: Mono: Playback [on] Jan 12 12:45:13 volumio volumio[1205]: info: VolumeController:: Volume=undefined Mute =false Jan 12 12:45:13 volumio volumio[1205]: info: CoreStateMachine::pushState Jan 12 12:45:13 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:13 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 12:45:13 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Jan 12 12:45:13 volumio volumio[1205]: info: CoreStateMachine::updateTrackBlock Jan 12 12:45:13 volumio volumio[1205]: info: CorePlayQueue::getTrackBlock Jan 12 12:45:13 volumio volumio[1205]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 12:45:14 volumio volumio[1205]: info: CoreStateMachine::setRepeat true single undefined Jan 12 12:45:14 volumio volumio[1205]: info: CoreStateMachine::pushState Jan 12 12:45:14 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Jan 12 12:45:14 volumio volumio[1205]: info: CoreStateMachine::setRandom undefined Jan 12 12:45:14 volumio volumio[1205]: info: CoreStateMachine::pushState Jan 12 12:45:14 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Jan 12 12:45:14 volumio volumio[1205]: info: Setting Device type: Raspberry PI Jan 12 12:45:14 volumio volumio[1205]: info: Listing playlists Jan 12 12:45:14 volumio volumio[1205]: info: Listing playlists Jan 12 12:45:14 volumio volumio[1205]: Unable to parse: Jan 12 12:45:14 volumio volumio[1205]: Simple mixer control 'PCM',0 Jan 12 12:45:14 volumio volumio[1205]: Capabilities: pswitch pswitch-joined Jan 12 12:45:14 volumio volumio[1205]: Playback channels: Mono Jan 12 12:45:14 volumio volumio[1205]: Mono: Playback [on] Jan 12 12:45:14 volumio volumio[1205]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Jan 12 12:45:14 volumio volumio[1205]: info: Discovery: adding 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Jan 12 12:45:14 volumio volumio[1205]: info: Discovery: Found device Volumio Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:14 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:14 volumio volumio[1205]: info: Discovery: this is already registered, 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Jan 12 12:45:14 volumio volumio[1205]: info: Discovery: Found device Volumio Jan 12 12:45:14 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:14 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:14 volumio volumio[1205]: Unable to parse: Jan 12 12:45:14 volumio volumio[1205]: Simple mixer control 'PCM',0 Jan 12 12:45:14 volumio volumio[1205]: Capabilities: pswitch pswitch-joined Jan 12 12:45:14 volumio volumio[1205]: Playback channels: Mono Jan 12 12:45:14 volumio volumio[1205]: Mono: Playback [on] Jan 12 12:45:14 volumio volumio[1205]: info: VolumeController:: Volume=undefined Mute =false Jan 12 12:45:14 volumio volumio[1205]: info: CoreStateMachine::pushState Jan 12 12:45:15 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:15 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Jan 12 12:45:15 volumio volumio[1205]: info: Completed loading Core Plugins Jan 12 12:45:15 volumio volumio[1205]: info: Preparing to generate the ALSA configuration file Jan 12 12:45:15 volumio sudo[1453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 12 12:45:15 volumio sudo[1453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:15 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 12 12:45:15 volumio volumio[1205]: info: Asound.conf file unchanged, so no further update is needed Jan 12 12:45:15 volumio volumio[1205]: info: Output device has changed, restarting MPD Jan 12 12:45:15 volumio volumio[1205]: info: Output device has changed, restarting Shairport Sync Jan 12 12:45:15 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:15 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:15 volumio sudo[1472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 12:45:15 volumio sudo[1468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 12:45:15 volumio sudo[1468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:15 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:15 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 12:45:15 volumio volumio[1205]: info: ___________ START PLUGINS ___________ Jan 12 12:45:16 volumio sudo[1468]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:16 volumio volumio[1205]: info: ControllerMpd::onStart: Initializing MPD Jan 12 12:45:16 volumio volumio[1205]: info: Creating MPD Configuration file Jan 12 12:45:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 12:45:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 12:45:16 volumio sudo[1486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 12:45:16 volumio sudo[1485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 12:45:16 volumio sudo[1485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:16 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 12:45:16 volumio sudo[1486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:16 volumio sudo[1486]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:16 volumio volumio[1205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 12:45:16 volumio volumio[1205]: info: [1768218316573] CoreMusicLibrary::Adding element Medienserver Jan 12 12:45:16 volumio sudo[1482]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 12:45:16 volumio sudo[1482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 12:45:16 volumio sudo[1494]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 12:45:16 volumio sudo[1482]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:16 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 12:45:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 12:45:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 12:45:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 12:45:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 12:45:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 12:45:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 12:45:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 12:45:16 volumio volumio[1205]: info: UPNP Browser: Client initialized successfully Jan 12 12:45:16 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 12 12:45:16 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 12 12:45:16 volumio systemd[1]: setdatetime-helper.service: Consumed 1.081s CPU time. Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:17 volumio sudo[1497]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 12:45:17 volumio sudo[1497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 12:45:17 volumio sudo[1503]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 12:45:17 volumio sudo[1497]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:17 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:17 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 12:45:17 volumio volumio[1205]: info: [1768218317548] CoreMusicLibrary::Adding element Last_100 Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 12:45:17 volumio volumio[1205]: info: [1768218317588] CoreMusicLibrary::Adding element Webradio Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 12:45:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 12:45:17 volumio volumio[1205]: info: Initializing BBC Radios Jan 12 12:45:18 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 12:45:18 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:18 volumio volumio[1205]: info: Creating Spotify config file Jan 12 12:45:18 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:21 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Jan 12 12:45:21 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 12:45:21 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 12:45:21 volumio sudo[1453]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:22 volumio volumio[1205]: info: Volumio Calling Home Jan 12 12:45:22 volumio volumio[1405]: Starting albumart workers Jan 12 12:45:23 volumio volumio[1406]: Starting albumart workers Jan 12 12:45:24 volumio volumio[1205]: info: MPD Permissions set Jan 12 12:45:24 volumio volumio[1205]: info: MPD Permissions set Jan 12 12:45:24 volumio volumio[1205]: info: Upmpdcli Daemon Started Jan 12 12:45:24 volumio mpd[1505]: 2026-01-12T12:45:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 12:45:24 volumio volumio[1404]: Starting albumart workers Jan 12 12:45:25 volumio volumio[1205]: info: Volumio called home Jan 12 12:45:25 volumio volumio[1205]: info: Spotify config file written Jan 12 12:45:25 volumio sudo[1557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 12 12:45:25 volumio sudo[1557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:25 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. Jan 12 12:45:25 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. Jan 12 12:45:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 12:45:25 volumio go-librespot[1559]: go-librespot daemon starting... Jan 12 12:45:25 volumio sudo[1557]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 12 12:45:25 volumio sudo[1485]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:25 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:25 volumio go-librespot[1560]: time="2026-01-12T12:45:25+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 12:45:25 volumio go-librespot[1560]: time="2026-01-12T12:45:25+01:00" level=debug msg="app state loaded" Jan 12 12:45:25 volumio go-librespot[1560]: time="2026-01-12T12:45:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+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-gae2.spotify.com:80]" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=info msg="zeroconf server listening on port 37629" Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="obtained new client token: AACdQpBbGSnxUgqZy3XSCnnVV6Dr/z9n8j+6aelAvn3sDHeQqs5QiYkXuzUQ5zKvOWG2bKwPbi3GpMfiJMhaSG2t3ZODgtcAzd1WkITI6C6sHEeOx6M2hw1RuDqSUCuMehDBW817oIWSMxu3ikasqfsv7TxhAaZ+9udk9Bi2jIHOt6g9ODlr5ErkbjLmfBgQxEEhrkVKfEYRSIR0iLht/g25usHDyixCn0OsV4MFeWKiUvIuAUBJ+NLH32g=" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="completed keyexchange" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="completed challenge" Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=info msg="authenticated AP" username="bu********pf" Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=info msg="authenticated Login5" username="bu********pf" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="initializing zeroconf session" username="bu********pf" Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:26 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="dealer connection opened" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=trace msg="starting accesspoint recv loop" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=trace msg="starting dealer recv loop" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=trace msg="received accesspoint ping" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 12 12:45:26 volumio go-librespot[1560]: time="2026-01-12T12:45:26+01:00" level=debug msg="received connection id: MDJjNTE0OGItOTM1...NkExM0QwNUVCRA==" Jan 12 12:45:26 volumio volumio[1205]: info: No need to fix Spotify hosts Jan 12 12:45:27 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:27 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:27 volumio go-librespot[1560]: time="2026-01-12T12:45:27+01:00" level=trace msg="received accesspoint pong ack" Jan 12 12:45:27 volumio go-librespot[1560]: time="2026-01-12T12:45:27+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 12 12:45:27 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 12 12:45:27 volumio volumio[1205]: info: Completed starting Core Plugins Jan 12 12:45:27 volumio volumio[1205]: info: ------------------------------------------- Jan 12 12:45:27 volumio volumio[1205]: info: ----- MyVolumio plugins startup ---- Jan 12 12:45:27 volumio volumio[1205]: info: ------------------------------------------- Jan 12 12:45:27 volumio volumio[1205]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 12 12:45:28 volumio volumio[1205]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 12:45:28 volumio volumio[1205]: SPOTIFY: BQASnhj6ucEkFHxPH4MrBPuF8XfdRj2ee6Z6cdX9ZHhrPizVNnl_c_3N5SILmLsxZxPIWy8b1RsZAzgCwPJcmVmJhVkw-azJW0M960dbjeJuMaH6rHj5G8iWbnkTfckBhY9BxegjqCSHduh-5Iq0iX7aaCvuGbIa7uGGVMaU8xAAjJ80j0Ag4D5AkgMfCvBkMpXwed5e6iYiXij9YGG8_aSrXdXXXO4GgrMQAREtA51PEKOZjlxiN0bHdGjPYlBzRpaCOcKa4d1EA7A4BE9D_w7osyDDvTkTEd28-3Q Jan 12 12:45:28 volumio volumio[1205]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 12:45:28 volumio volumio[1205]: info: New Spotify access token = BQASnhj6ucEkFHxPH4MrBPuF8XfdRj2ee6Z6cdX9ZHhrPizVNnl_c_3N5SILmLsxZxPIWy8b1RsZAzgCwPJcmVmJhVkw-azJW0M960dbjeJuMaH6rHj5G8iWbnkTfckBhY9BxegjqCSHduh-5Iq0iX7aaCvuGbIa7uGGVMaU8xAAjJ80j0Ag4D5AkgMfCvBkMpXwed5e6iYiXij9YGG8_aSrXdXXXO4GgrMQAREtA51PEKOZjlxiN0bHdGjPYlBzRpaCOcKa4d1EA7A4BE9D_w7osyDDvTkTEd28-3Q Jan 12 12:45:28 volumio volumio[1205]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 12 12:45:29 volumio volumio[1205]: error: MPD error: The expression evaluated to a falsy value: Jan 12 12:45:29 volumio volumio[1205]: assert.ok(self.idling) Jan 12 12:45:29 volumio volumio[1205]: error: The expression evaluated to a falsy value: Jan 12 12:45:29 volumio volumio[1205]: assert.ok(self.idling) Jan 12 12:45:29 volumio volumio[1205]: info: MPD running with PID1505 Jan 12 12:45:29 volumio volumio[1205]: ,establishing connection Jan 12 12:45:29 volumio volumio[1205]: info: Starting Shairport Sync Jan 12 12:45:29 volumio volumio[1205]: info: Starting Shairport Sync Jan 12 12:45:29 volumio volumio[1205]: info: Starting Shairport Sync Jan 12 12:45:29 volumio volumio[1205]: error: updateQueue error: null Jan 12 12:45:29 volumio volumio[1205]: error: updateQueue error: null Jan 12 12:45:29 volumio sudo[1601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 12:45:29 volumio sudo[1601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:29 volumio sudo[1605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 12:45:29 volumio sudo[1605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:29 volumio sudo[1603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 12:45:29 volumio sudo[1603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 12:45:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 12:45:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 12:45:29 volumio systemd[1]: shairport-sync.service: Consumed 1.431s CPU time. Jan 12 12:45:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 12:45:29 volumio sudo[1601]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:29 volumio sudo[1605]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 12:45:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 12:45:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 12:45:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 12:45:29 volumio sudo[1603]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:30 volumio volumio[1205]: info: Shairport-Sync Started Jan 12 12:45:30 volumio volumio[1205]: Error adding Membership: Error: addMembership EINVAL Jan 12 12:45:30 volumio volumio[1205]: info: Shairport-Sync Started Jan 12 12:45:30 volumio volumio[1205]: info: Shairport-Sync Started Jan 12 12:45:30 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:30 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:30 volumio volumio[1205]: 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"} Jan 12 12:45:30 volumio volumio[1205]: info: Spotify Successfully logged in Jan 12 12:45:30 volumio volumio[1205]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 12:45:30 volumio volumio[1205]: info: [1768218330313] CoreMusicLibrary::Adding element Spotify Jan 12 12:45:30 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 12:45:30 volumio volumio[1205]: Cannot find translation for source Spotify Jan 12 12:45:30 volumio volumio[1205]: info: go-librespot daemon successfully initialized Jan 12 12:45:31 volumio sudo[1626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 12:45:31 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:31 volumio sudo[1628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 12:45:31 volumio sudo[1628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 12:45:31 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 12 12:45:31 volumio sudo[1628]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:31 volumio mpd_monitor.sh[1631]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 12:45:31 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 12 12:45:31 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 12 12:45:31 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 12 12:45:31 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 12 12:45:31 volumio mpd_monitor.sh[1634]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 12:45:31 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root Jan 12 12:45:31 volumio volumio[1205]: info: Successfully started MPD Monitor Jan 12 12:45:31 volumio volumio[1205]: info: Successfully started MPD Monitor Jan 12 12:45:33 volumio volumio[1205]: info: Initializing connection to go-librespot Websocket Jan 12 12:45:34 volumio go-librespot[1560]: time="2026-01-12T12:45:34+01:00" level=debug msg="new websocket client" Jan 12 12:45:34 volumio volumio[1205]: info: Connection to go-librespot Websocket established Jan 12 12:45:34 volumio volumio[1205]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 12 12:45:39 volumio volumio[1205]: info: Getting Spotify volume Jan 12 12:45:45 volumio volumio[1205]: info: Spotify volume: 100 Jan 12 12:45:46 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Jan 12 12:45:46 volumio volumio[1205]: info: CorePlayQueue::getTrack 0 Jan 12 12:45:46 volumio volumio[1205]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 12 12:45:49 volumio volumio[1205]: info: Listing playlists Jan 12 12:45:49 volumio volumio[1205]: info: Listing playlists Jan 12 12:45:49 volumio volumio[1205]: error: MyVolumio Plugin failed to start in a timely fashion Jan 12 12:45:49 volumio volumio[1205]: [Metrics] CommandRouter: 53s 147.37ms Jan 12 12:45:49 volumio volumio[1205]: info: CoreCommandRouter::volumiosetStartupVolume Jan 12 12:45:49 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 12:45:49 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:45:49 volumio volumio[1205]: info: CoreCommandRouter::Close All Modals sent Jan 12 12:45:49 volumio volumio[1205]: info: CoreCommandRouter::Close All Modals sent Jan 12 12:45:56 volumio go-librespot[1560]: time="2026-01-12T12:45:56+01:00" level=trace msg="sent dealer ping" Jan 12 12:45:57 volumio go-librespot[1560]: time="2026-01-12T12:45:57+01:00" level=trace msg="received dealer pong" Jan 12 12:45:57 volumio upmpdcli[1691]: writing RSA key Jan 12 12:46:04 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 12 12:46:04 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 12:46:04 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 12 12:46:05 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 12:46:05 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 12:46:05 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 12 12:46:05 volumio volumio[1205]: info: BOOT COMPLETED Jan 12 12:46:26 volumio go-librespot[1560]: time="2026-01-12T12:46:26+01:00" level=trace msg="sent dealer ping" Jan 12 12:46:26 volumio go-librespot[1560]: time="2026-01-12T12:46:26+01:00" level=trace msg="received dealer pong" Jan 12 12:46:37 volumio volumio[1205]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 12:46:37 volumio volumio[1205]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Jan 12 12:46:37 volumio volumio[1205]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Jan 12 12:46:37 volumio volumio[1205]: at new NodeError (node:internal/errors:405:5) Jan 12 12:46:37 volumio volumio[1205]: at assert (node:internal/assert:14:11) Jan 12 12:46:37 volumio volumio[1205]: at internalConnectMultiple (node:net:1118:3) Jan 12 12:46:37 volumio volumio[1205]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Jan 12 12:46:37 volumio volumio[1205]: at listOnTimeout (node:internal/timers:575:11) Jan 12 12:46:37 volumio volumio[1205]: at process.processTimers (node:internal/timers:514:7) { Jan 12 12:46:37 volumio volumio[1205]: code: 'ERR_INTERNAL_ASSERTION' Jan 12 12:46:37 volumio volumio[1205]: } Jan 12 12:46:37 volumio volumio[1205]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 12:46:43 volumio sudo[1778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 12:45' Jan 12 12:46:43 volumio sudo[1778]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"