Dec 19 08:32:44 volumio ntpd[890]: CLOCK: time stepped by 133737.497628 Dec 19 08:32:44 volumio ntpd[890]: CLOCK: time changed from 2025-12-17 to 2025-12-19 Dec 19 08:32:44 volumio ntpd[890]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 19 08:32:44 volumio volumio-remote-updater[691]: [2025-12-19 08:32:44] [connect] Successful connection Dec 19 08:32:44 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Dec 19 08:32:44 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Dec 19 08:32:44 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Dec 19 08:32:44 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Dec 19 08:32:44 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Dec 19 08:32:45 volumio volumio[1199]: info: MYVOLUMIO Environment detected Dec 19 08:32:45 volumio volumio[1199]: info: Plugin folders cleanup Dec 19 08:32:45 volumio volumio[1199]: info: Scanning into folder /volumio/app/plugins/ Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category audio_interface Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category miscellanea Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category music_service Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category plugins.json Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category system_controller Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category user_interface Dec 19 08:32:45 volumio volumio[1199]: info: Scanning into folder /data/plugins/ Dec 19 08:32:45 volumio volumio[1199]: info: Scanning category music_service Dec 19 08:32:45 volumio volumio[1199]: info: Plugin folders cleanup completed Dec 19 08:32:45 volumio volumio[1199]: info: ------------------------------------------- Dec 19 08:32:45 volumio volumio[1199]: info: ----- Core plugins startup ---- Dec 19 08:32:45 volumio volumio[1199]: info: ------------------------------------------- Dec 19 08:32:45 volumio volumio[1199]: info: Loading plugins from folder /volumio/app/plugins/ Dec 19 08:32:45 volumio volumio[1199]: info: Adding plugin upnp to MyMusic Plugins Dec 19 08:32:45 volumio volumio[1199]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 19 08:32:45 volumio volumio[1199]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 19 08:32:45 volumio volumio[1199]: info: Loading plugins from folder /data/plugins/ Dec 19 08:32:45 volumio volumio[1199]: info: Loading plugin "system"... Dec 19 08:32:46 volumio volumio[1199]: info: Loading plugin "appearance"... Dec 19 08:32:48 volumio volumio[1199]: info: Loading plugin "network"... Dec 19 08:32:48 volumio volumio[1199]: info: Refreshing Cached IP Addresses Dec 19 08:32:48 volumio sudo[1294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 19 08:32:48 volumio sudo[1293]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 19 08:32:48 volumio sudo[1293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:48 volumio sudo[1293]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:48 volumio sudo[1294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:48 volumio volumio[1199]: info: Loading plugin "services"... Dec 19 08:32:48 volumio volumio[1199]: info: Loading plugin "alsa_controller"... Dec 19 08:32:48 volumio sudo[1294]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:48 volumio sudo[1301]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 19 08:32:48 volumio sudo[1301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:48 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 08:32:48 volumio volumio[1199]: info: Loading plugin "wizard"... Dec 19 08:32:48 volumio volumio[1199]: info: Loading plugin "networkfs"... Dec 19 08:32:49 volumio volumio[1199]: info: Starting Udev Watcher for removable devices Dec 19 08:32:49 volumio sudo[1326]: 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 Dec 19 08:32:49 volumio sudo[1326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:49 volumio sudo[1328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kodi,password=kodi,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //nas.buster.lan/multimedia\\Musik /mnt/NAS/nas Dec 19 08:32:49 volumio sudo[1328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:49 volumio volumio[1199]: info: Ignoring mount for partition: boot Dec 19 08:32:49 volumio volumio[1199]: info: Ignoring mount for partition: volumio Dec 19 08:32:49 volumio volumio[1199]: info: Ignoring mount for partition: volumio_data Dec 19 08:32:49 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 19 08:32:49 volumio volumio[1199]: info: Loading plugin "volumio_command_line_client"... Dec 19 08:32:49 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 19 08:32:49 volumio volumio[1199]: info: Loading plugin "upnp"... Dec 19 08:32:49 volumio volumio[1199]: info: [1766129569339] Starting Upmpd Daemon Dec 19 08:32:49 volumio kernel: netfs: FS-Cache loaded Dec 19 08:32:49 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 19 08:32:49 volumio volumio[1199]: info: Loading plugin "my_music"... Dec 19 08:32:49 volumio volumio[1199]: info: Loading plugin "mpd"... Dec 19 08:32:49 volumio kernel: Key type cifs.spnego registered Dec 19 08:32:49 volumio kernel: Key type cifs.idmap registered Dec 19 08:32:49 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. Dec 19 08:32:49 volumio kernel: CIFS: Attempting to mount //nas.buster.lan/multimedia/Musik Dec 19 08:32:49 volumio sudo[1301]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:49 volumio sudo[1328]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:49 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 19 08:32:49 volumio kernel: CIFS: VFS: \\nas.buster.lan Send error in SessSetup = -13 Dec 19 08:32:49 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Dec 19 08:32:49 volumio kernel: CIFS: Attempting to mount //192.168.1.5/multimedia/Musik Dec 19 08:32:50 volumio sudo[1326]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:50 volumio volumio[1199]: info: Loading plugin "upnp_browser"... Dec 19 08:32:50 volumio dhcpcd[652]: timed out Dec 19 08:32:50 volumio sh[640]: timed out Dec 19 08:32:50 volumio sh[608]: ifup: failed to bring up eth0 Dec 19 08:32:50 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 19 08:32:50 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 19 08:32:52 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 19 08:32:52 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 19 08:32:52 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 19 08:32:52 volumio upmpdcli[1370]: Could not open config: /tmp/upmpdcli.conf Dec 19 08:32:52 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 19 08:32:52 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 19 08:32:53 volumio volumio[1199]: info: Starting UPNP Browser Dec 19 08:32:53 volumio volumio[1199]: info: Loading plugin "alarm-clock"... Dec 19 08:32:53 volumio volumio[1199]: info: Loading plugin "airplay_emulation"... Dec 19 08:32:54 volumio volumio[1199]: info: Starting Shairport Sync Dec 19 08:32:54 volumio volumio[1199]: info: Loading plugin "last_100"... Dec 19 08:32:54 volumio volumio[1199]: info: Loading plugin "webradio"... Dec 19 08:32:54 volumio volumio[1199]: info: Loading plugin "i2s_dacs"... Dec 19 08:32:54 volumio volumio[1199]: info: I2S DAC not set, start Auto-detection Dec 19 08:32:54 volumio volumio[1199]: info: Loading plugin "volumiodiscovery"... Dec 19 08:32:54 volumio volumio[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 19 08:32:54 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 08:32:54 volumio volumio[1199]: *** WARNING *** For more information see Dec 19 08:32:54 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. Dec 19 08:32:54 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 08:32:54 volumio volumio[1199]: *** WARNING *** For more information see Dec 19 08:32:54 volumio node[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 19 08:32:54 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 08:32:54 volumio node[1199]: *** WARNING *** For more information see Dec 19 08:32:54 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. Dec 19 08:32:54 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 19 08:32:54 volumio node[1199]: *** WARNING *** For more information see Dec 19 08:32:54 volumio volumio[1199]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 19 08:32:54 volumio volumio[1199]: info: Discovery: Started advertising with name: Volumio Dec 19 08:32:54 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 19 08:32:54 volumio volumio[1199]: info: Loading plugin "spop"... Dec 19 08:32:55 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "outputs"... Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "albumart"... Dec 19 08:32:58 volumio volumio[1199]: info: Plugin example_plugin is not enabled Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "inputs"... Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "updater_comm"... Dec 19 08:32:58 volumio volumio[1199]: info: Plugin mpdemulation is not enabled Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "rest_api"... Dec 19 08:32:58 volumio volumio[1199]: info: Loading plugin "websocket"... Dec 19 08:32:58 volumio volumio[1199]: info: Starting Socket.io Server version 1.7.4 Dec 19 08:32:58 volumio volumio[1199]: info: Loading i18n strings for locale de Dec 19 08:32:58 volumio volumio[1199]: Updating browse sources language Dec 19 08:32:58 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::initPlayerControls Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 08:32:59 volumio volumio[1199]: Express server listening on port 3000 Dec 19 08:32:59 volumio volumio[1199]: [Metrics] WebUI: 16s 351.76ms Dec 19 08:32:59 volumio volumio[1199]: info: CoreStateMachine::resetVolumioState Dec 19 08:32:59 volumio volumio[1199]: info: CoreStateMachine::getcurrentVolume Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Dec 19 08:32:59 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:32:59 volumio sudo[1407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 19 08:32:59 volumio sudo[1407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:59 volumio sudo[1407]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:59 volumio sudo[1409]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 19 08:32:59 volumio sudo[1409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:32:59 volumio sudo[1409]: pam_unix(sudo:session): session closed for user root Dec 19 08:32:59 volumio volumio-remote-updater[691]: [2025-12-19 08:32:59] [connect] Successful connection Dec 19 08:32:59 volumio volumio[1199]: info: Volumio Network Manager: Network status updated: 2 Dec 19 08:32:59 volumio volumio[1199]: Unable to parse: Dec 19 08:32:59 volumio volumio[1199]: Simple mixer control 'PCM',0 Dec 19 08:32:59 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Dec 19 08:32:59 volumio volumio[1199]: Playback channels: Mono Dec 19 08:32:59 volumio volumio[1199]: Mono: Playback [on] Dec 19 08:32:59 volumio volumio[1199]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Dec 19 08:32:59 volumio volumio[1199]: info: Cannot mount NAS nas at system boot, trial number 1 ,retrying in 5 seconds Dec 19 08:32:59 volumio volumio[1199]: Unable to parse: Dec 19 08:32:59 volumio volumio[1199]: Simple mixer control 'PCM',0 Dec 19 08:32:59 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Dec 19 08:32:59 volumio volumio[1199]: Playback channels: Mono Dec 19 08:32:59 volumio volumio[1199]: Mono: Playback [on] Dec 19 08:33:00 volumio volumio[1199]: info: VolumeController:: Volume=undefined Mute =false Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::pushState Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::updateTrackBlock Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrackBlock Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Dec 19 08:33:00 volumio volumio-remote-updater[691]: [2025-12-19 08:33:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1766129579 101 Dec 19 08:33:00 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 Dec 19 08:33:00 volumio volumio[1199]: info: Reloading queue from file Dec 19 08:33:00 volumio volumio[1378]: Forking 3 albumart workers Dec 19 08:33:00 volumio volumio[1199]: Unable to parse: Dec 19 08:33:00 volumio volumio[1199]: Simple mixer control 'PCM',0 Dec 19 08:33:00 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Dec 19 08:33:00 volumio volumio[1199]: Playback channels: Mono Dec 19 08:33:00 volumio volumio[1199]: Mono: Playback [on] Dec 19 08:33:00 volumio volumio[1199]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::setRepeat true single undefined Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::pushState Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::setRandom undefined Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::pushState Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Dec 19 08:33:00 volumio volumio[1199]: info: Setting Device type: Raspberry PI Dec 19 08:33:00 volumio volumio[1199]: Unable to parse: Dec 19 08:33:00 volumio volumio[1199]: Simple mixer control 'PCM',0 Dec 19 08:33:00 volumio volumio[1199]: Capabilities: pswitch pswitch-joined Dec 19 08:33:00 volumio volumio[1199]: Playback channels: Mono Dec 19 08:33:00 volumio volumio[1199]: Mono: Playback [on] Dec 19 08:33:00 volumio volumio[1199]: info: VolumeController:: Volume=undefined Mute =false Dec 19 08:33:00 volumio volumio[1199]: info: CoreStateMachine::pushState Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Dec 19 08:33:00 volumio volumio[1199]: info: Discovery: adding 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Dec 19 08:33:00 volumio volumio[1199]: info: Discovery: Found device Volumio Dec 19 08:33:00 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 19 08:33:00 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:00 volumio sudo[1452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 19 08:33:00 volumio sudo[1452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:01 volumio volumio[1199]: info: Completed loading Core Plugins Dec 19 08:33:01 volumio volumio[1199]: info: Preparing to generate the ALSA configuration file Dec 19 08:33:01 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 19 08:33:01 volumio volumio[1199]: info: Discovery: this is already registered, 3aeb59d2-4c76-4169-87ff-77ce4f6a744b Dec 19 08:33:01 volumio volumio[1199]: info: Discovery: Found device Volumio Dec 19 08:33:01 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 19 08:33:01 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:01 volumio volumio[1199]: info: Asound.conf file unchanged, so no further update is needed Dec 19 08:33:01 volumio volumio[1199]: info: Output device has changed, restarting MPD Dec 19 08:33:01 volumio volumio[1199]: info: Output device has changed, restarting Shairport Sync Dec 19 08:33:01 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:01 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:01 volumio sudo[1474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 19 08:33:01 volumio sudo[1472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 19 08:33:01 volumio sudo[1474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:01 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:01 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:01 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 19 08:33:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 19 08:33:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 19 08:33:02 volumio volumio[1199]: info: ___________ START PLUGINS ___________ Dec 19 08:33:02 volumio volumio[1199]: info: ControllerMpd::onStart: Initializing MPD Dec 19 08:33:02 volumio volumio[1199]: info: Creating MPD Configuration file Dec 19 08:33:02 volumio sudo[1484]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 19 08:33:02 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 19 08:33:02 volumio sudo[1486]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 19 08:33:02 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:02 volumio sudo[1490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 19 08:33:02 volumio sudo[1490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 08:33:02 volumio volumio[1199]: info: [1766129582379] CoreMusicLibrary::Adding element Medienserver Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 08:33:02 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 19 08:33:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 19 08:33:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 19 08:33:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 19 08:33:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 19 08:33:02 volumio volumio[1199]: info: UPNP Browser: Client initialized successfully Dec 19 08:33:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 19 08:33:02 volumio sudo[1488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 19 08:33:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:02 volumio sudo[1488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:02 volumio sudo[1488]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:02 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:02 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:02 volumio sudo[1493]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 19 08:33:02 volumio sudo[1493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 19 08:33:02 volumio sudo[1502]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 19 08:33:02 volumio sudo[1493]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:03 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 08:33:03 volumio volumio[1199]: info: [1766129583089] CoreMusicLibrary::Adding element Last_100 Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 08:33:03 volumio volumio[1199]: info: [1766129583164] CoreMusicLibrary::Adding element Webradio Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 08:33:03 volumio volumio[1199]: info: Initializing BBC Radios Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:03 volumio volumio[1199]: info: Creating Spotify config file Dec 19 08:33:03 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:05 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 19 08:33:05 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 19 08:33:05 volumio systemd[1]: setdatetime-helper.service: Consumed 1.081s CPU time. Dec 19 08:33:07 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 19 08:33:07 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 19 08:33:08 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 19 08:33:08 volumio sudo[1452]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:08 volumio volumio[1199]: info: Volumio Calling Home Dec 19 08:33:10 volumio volumio[1424]: Starting albumart workers Dec 19 08:33:10 volumio mpd[1503]: 2025-12-19T08:33:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 19 08:33:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 19 08:33:11 volumio sudo[1490]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:11 volumio sudo[1474]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:11 volumio sudo[1558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kodi,password=kodi,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //nas.buster.lan/multimedia\\Musik /mnt/NAS/nas Dec 19 08:33:11 volumio sudo[1558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:11 volumio volumio[1423]: Starting albumart workers Dec 19 08:33:12 volumio kernel: CIFS: Attempting to mount //nas.buster.lan/multimedia/Musik Dec 19 08:33:12 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 19 08:33:12 volumio kernel: CIFS: VFS: \\nas.buster.lan Send error in SessSetup = -13 Dec 19 08:33:12 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Dec 19 08:33:12 volumio sudo[1558]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:12 volumio volumio[1199]: info: Completed starting Core Plugins Dec 19 08:33:12 volumio volumio[1199]: info: ------------------------------------------- Dec 19 08:33:12 volumio volumio[1199]: info: ----- MyVolumio plugins startup ---- Dec 19 08:33:12 volumio volumio[1199]: info: ------------------------------------------- Dec 19 08:33:12 volumio volumio[1199]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 19 08:33:12 volumio volumio[1199]: info: MPD Permissions set Dec 19 08:33:12 volumio volumio[1199]: info: MPD Permissions set Dec 19 08:33:12 volumio volumio[1199]: info: Upmpdcli Daemon Started Dec 19 08:33:12 volumio volumio[1199]: info: MPD running with PID1503 Dec 19 08:33:12 volumio volumio[1199]: ,establishing connection Dec 19 08:33:12 volumio volumio[1199]: info: Cannot mount NAS nas at system boot, trial number 2 ,retrying in 5 seconds Dec 19 08:33:12 volumio volumio[1199]: info: Volumio called home Dec 19 08:33:12 volumio volumio[1199]: info: Spotify config file written Dec 19 08:33:12 volumio sudo[1569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 19 08:33:12 volumio sudo[1569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:12 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. Dec 19 08:33:12 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. Dec 19 08:33:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 19 08:33:12 volumio go-librespot[1571]: go-librespot daemon starting... Dec 19 08:33:12 volumio sudo[1569]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:13 volumio volumio[1425]: Starting albumart workers Dec 19 08:33:13 volumio go-librespot[1572]: time="2025-12-19T08:33:13+01:00" level=info msg="running go-librespot 0.4.0" Dec 19 08:33:13 volumio go-librespot[1572]: time="2025-12-19T08:33:13+01:00" level=debug msg="app state loaded" Dec 19 08:33:13 volumio go-librespot[1572]: time="2025-12-19T08:33:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=info msg="zeroconf server listening on port 43261" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="obtained new client token: AADfp+f3iaqVCfEEzx7GftdvoZ2ToFPxAugOCd723DHkj4n2/E+7Z5UoU9Gt2t1eVpQGq5v3doN/h3/d5gjjqtnMpAaff+Cm2xZ0Zv/voIEu1o7O7cZcO927vLru2bWDIHYMiS098K4429GGHnY56gceeFXKXuBkkXpXdMvMLP7hK5pah3GdE710EabHhVN/DFGWkUr3ZNRNi7k1Rmt6IZVtln+JHWM+1aESSG/xqCixmcpliPNQyUmx" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="completed keyexchange" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="completed challenge" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=info msg="authenticated AP" username="bu********pf" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=info msg="authenticated Login5" username="bu********pf" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="initializing zeroconf session" username="bu********pf" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="dealer connection opened" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=trace msg="starting accesspoint recv loop" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=trace msg="starting dealer recv loop" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=trace msg="received accesspoint ping" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="received connection id: ODYwMDY2MjUtYWM2...MjVFNjlGMkQ1MA==" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 19 08:33:14 volumio go-librespot[1572]: time="2025-12-19T08:33:14+01:00" level=trace msg="received accesspoint pong ack" Dec 19 08:33:14 volumio volumio[1199]: error: MPD error: The expression evaluated to a falsy value: Dec 19 08:33:14 volumio volumio[1199]: assert.ok(self.idling) Dec 19 08:33:14 volumio volumio[1199]: error: The expression evaluated to a falsy value: Dec 19 08:33:14 volumio volumio[1199]: assert.ok(self.idling) Dec 19 08:33:14 volumio volumio[1199]: error: MPD error: The expression evaluated to a falsy value: Dec 19 08:33:14 volumio volumio[1199]: assert.ok(self.idling) Dec 19 08:33:15 volumio volumio[1199]: error: The expression evaluated to a falsy value: Dec 19 08:33:15 volumio volumio[1199]: assert.ok(self.idling) Dec 19 08:33:15 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: 2 Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio sudo[1584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 19 08:33:15 volumio sudo[1584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:15 volumio sudo[1581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 19 08:33:15 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:15 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 19 08:33:15 volumio mpd_monitor.sh[1596]: MPD Monitor Service: Starting MPD Monitor Service Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:15 volumio sudo[1584]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:15 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 19 08:33:15 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:16 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 19 08:33:16 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 19 08:33:16 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:16 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:16 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:16 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 19 08:33:16 volumio mpd_monitor.sh[1602]: MPD Monitor Service: Starting MPD Monitor Service Dec 19 08:33:16 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:16 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:16 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:16 volumio volumio[1199]: info: No need to fix Spotify hosts Dec 19 08:33:17 volumio volumio[1199]: error: updateQueue error: null Dec 19 08:33:17 volumio volumio[1199]: info: Successfully started MPD Monitor Dec 19 08:33:17 volumio volumio[1199]: info: Successfully started MPD Monitor Dec 19 08:33:17 volumio volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 19 08:33:17 volumio volumio[1199]: SPOTIFY: BQCZckSPfeBFZGoo8LvOhtJoLQxYVdiEKeR4D457ufTEq65ZQNMvITacysWPxDe4M-YPIL-17aKreGrEaJJERzlaj3L6oGquXyDBrcfq8KMioQe3AimiUnJdvYI8vcINqNM9x3_g8dpL5Qawrlbi6VSdckV6ai21jSVLY1eH1JMekyZPtnwbgTY01Jsn1uNt-m6wJ0nZaogQu3zOMS2kJhhCHB_tKDrsMmvW5oZnTwcSVeaPyFxic3DU_rPv-zYmi--NL2Ai3JpXx6MSQrPXC7AK1QEhMuhxbpiojqg Dec 19 08:33:17 volumio volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 19 08:33:17 volumio volumio[1199]: info: New Spotify access token = BQCZckSPfeBFZGoo8LvOhtJoLQxYVdiEKeR4D457ufTEq65ZQNMvITacysWPxDe4M-YPIL-17aKreGrEaJJERzlaj3L6oGquXyDBrcfq8KMioQe3AimiUnJdvYI8vcINqNM9x3_g8dpL5Qawrlbi6VSdckV6ai21jSVLY1eH1JMekyZPtnwbgTY01Jsn1uNt-m6wJ0nZaogQu3zOMS2kJhhCHB_tKDrsMmvW5oZnTwcSVeaPyFxic3DU_rPv-zYmi--NL2Ai3JpXx6MSQrPXC7AK1QEhMuhxbpiojqg Dec 19 08:33:17 volumio volumio[1199]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 19 08:33:17 volumio volumio[1199]: info: Starting Shairport Sync Dec 19 08:33:17 volumio volumio[1199]: info: Starting Shairport Sync Dec 19 08:33:17 volumio volumio[1199]: info: Starting Shairport Sync Dec 19 08:33:17 volumio sudo[1617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kodi,password=kodi,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //nas.buster.lan/multimedia\\Musik /mnt/NAS/nas Dec 19 08:33:17 volumio sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:17 volumio sudo[1619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 19 08:33:17 volumio sudo[1619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:17 volumio kernel: CIFS: Attempting to mount //nas.buster.lan/multimedia/Musik Dec 19 08:33:17 volumio sudo[1621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 19 08:33:17 volumio sudo[1621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:17 volumio sudo[1617]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:17 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 19 08:33:17 volumio kernel: CIFS: VFS: \\nas.buster.lan Send error in SessSetup = -13 Dec 19 08:33:17 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Dec 19 08:33:17 volumio sudo[1623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 19 08:33:17 volumio sudo[1623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 19 08:33:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 19 08:33:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 19 08:33:18 volumio systemd[1]: shairport-sync.service: Consumed 1.517s CPU time. Dec 19 08:33:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 19 08:33:18 volumio sudo[1619]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 19 08:33:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 19 08:33:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 19 08:33:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 19 08:33:18 volumio sudo[1621]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:18 volumio sudo[1623]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:18 volumio volumio[1199]: info: Cannot mount NAS nas at system boot, trial number 3 ,retrying in 5 seconds Dec 19 08:33:18 volumio volumio[1199]: info: Shairport-Sync Started Dec 19 08:33:18 volumio volumio[1199]: Error adding Membership: Error: addMembership EINVAL Dec 19 08:33:18 volumio volumio[1199]: info: Shairport-Sync Started Dec 19 08:33:18 volumio volumio[1199]: info: Shairport-Sync Started Dec 19 08:33:19 volumio volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 19 08:33:19 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 19 08:33:19 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"} Dec 19 08:33:19 volumio volumio[1199]: info: Spotify Successfully logged in Dec 19 08:33:19 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 19 08:33:19 volumio volumio[1199]: info: [1766129599930] CoreMusicLibrary::Adding element Spotify Dec 19 08:33:19 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 19 08:33:19 volumio volumio[1199]: Cannot find translation for source Spotify Dec 19 08:33:20 volumio volumio[1199]: info: go-librespot daemon successfully initialized Dec 19 08:33:20 volumio volumio[1199]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 19 08:33:24 volumio volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 19 08:33:24 volumio sudo[1669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kodi,password=kodi,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //nas.buster.lan/multimedia\\Musik /mnt/NAS/nas Dec 19 08:33:24 volumio sudo[1669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:24 volumio kernel: CIFS: Attempting to mount //nas.buster.lan/multimedia/Musik Dec 19 08:33:24 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 19 08:33:24 volumio kernel: CIFS: VFS: \\nas.buster.lan Send error in SessSetup = -13 Dec 19 08:33:24 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Dec 19 08:33:24 volumio sudo[1669]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:41 volumio go-librespot[1572]: time="2025-12-19T08:33:41+01:00" level=debug msg="new websocket client" Dec 19 08:33:42 volumio volumio[1199]: info: Cannot mount NAS nas at system boot, trial number 4 ,retrying in 5 seconds Dec 19 08:33:42 volumio volumio[1199]: error: MyVolumio Plugin failed to start in a timely fashion Dec 19 08:33:42 volumio volumio[1199]: [Metrics] CommandRouter: 58s 172.49ms Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::volumiosetStartupVolume Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::Close All Modals sent Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::Close All Modals sent Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 19 08:33:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 19 08:33:44 volumio go-librespot[1572]: time="2025-12-19T08:33:44+01:00" level=trace msg="sent dealer ping" Dec 19 08:33:44 volumio go-librespot[1572]: time="2025-12-19T08:33:44+01:00" level=trace msg="received dealer pong" Dec 19 08:33:48 volumio volumio[1199]: info: Connection to go-librespot Websocket established Dec 19 08:33:48 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 19 08:33:48 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 19 08:33:49 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 19 08:33:49 volumio volumio[1199]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 08:33:49 volumio volumio[1199]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Dec 19 08:33:49 volumio volumio[1199]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Dec 19 08:33:49 volumio volumio[1199]: at new NodeError (node:internal/errors:405:5) Dec 19 08:33:49 volumio volumio[1199]: at assert (node:internal/assert:14:11) Dec 19 08:33:49 volumio volumio[1199]: at internalConnectMultiple (node:net:1118:3) Dec 19 08:33:49 volumio volumio[1199]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Dec 19 08:33:49 volumio volumio[1199]: at listOnTimeout (node:internal/timers:575:11) Dec 19 08:33:49 volumio volumio[1199]: at process.processTimers (node:internal/timers:514:7) { Dec 19 08:33:49 volumio volumio[1199]: code: 'ERR_INTERNAL_ASSERTION' Dec 19 08:33:49 volumio volumio[1199]: } Dec 19 08:33:49 volumio volumio[1199]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 19 08:33:49 volumio sudo[1714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=kodi,password=kodi,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //nas.buster.lan/multimedia\\Musik /mnt/NAS/nas Dec 19 08:33:49 volumio sudo[1714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 19 08:33:49 volumio kernel: CIFS: Attempting to mount //nas.buster.lan/multimedia/Musik Dec 19 08:33:49 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Dec 19 08:33:49 volumio kernel: CIFS: VFS: \\nas.buster.lan Send error in SessSetup = -13 Dec 19 08:33:49 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Dec 19 08:33:49 volumio sudo[1714]: pam_unix(sudo:session): session closed for user root Dec 19 08:33:55 volumio sudo[1747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-19 08:32' Dec 19 08:33:55 volumio sudo[1747]: 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"