-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Mon 2026-01-12 16:34:03 CET. -- Jan 12 16:33:47 loggia systemd-timedated[1031]: Changed local time to Mon Jan 12 16:33:47 2026 Jan 12 16:33:47 loggia sudo[1029]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:47 loggia volumio-time-update[649]: volumio-time-update-util: System time updated successfully. Jan 12 16:33:47 loggia systemd[1]: Starting Daily apt download activities... Jan 12 16:33:47 loggia systemd[1]: Started Volumio Time Update Utility. Jan 12 16:33:47 loggia volumio[994]: info: Loading plugin "network"... Jan 12 16:33:47 loggia volumio[994]: info: Refreshing Cached IP Addresses Jan 12 16:33:47 loggia sudo[1034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 16:33:47 loggia sudo[1034]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:47 loggia sudo[1034]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:47 loggia sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 16:33:47 loggia sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:47 loggia sudo[1037]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:47 loggia volumio[994]: info: Loading plugin "services"... Jan 12 16:33:47 loggia volumio[994]: info: Loading plugin "alsa_controller"... Jan 12 16:33:47 loggia sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 12 16:33:47 loggia sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:47 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:33:47 loggia volumio[994]: info: Loading plugin "wizard"... Jan 12 16:33:47 loggia volumio[994]: info: Loading plugin "networkfs"... Jan 12 16:33:47 loggia nmbd[725]: [2026/01/12 16:33:47.257506, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 12 16:33:47 loggia nmbd[725]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 12 16:33:47 loggia systemd[1]: Started Samba NMB Daemon. Jan 12 16:33:47 loggia systemd[1]: Starting Samba Winbind Daemon... Jan 12 16:33:47 loggia volumio[994]: info: Starting Udev Watcher for removable devices Jan 12 16:33:47 loggia sudo[1076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Kurti,password=Zielgerade12!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.2/Musikserver /mnt/NAS/Synology Jan 12 16:33:47 loggia sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:47 loggia volumio[994]: info: Ignoring mount for partition: boot Jan 12 16:33:47 loggia volumio[994]: info: Ignoring mount for partition: volumio Jan 12 16:33:47 loggia volumio[994]: info: Ignoring mount for partition: volumio_data Jan 12 16:33:47 loggia volumio[994]: info: Mounting Device Musikserver Jan 12 16:33:47 loggia sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Musikserver -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 12 16:33:47 loggia sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:47 loggia winbindd[1067]: [2026/01/12 16:33:47.516858, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 12 16:33:47 loggia winbindd[1067]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 12 16:33:47 loggia winbindd[1067]: [2026/01/12 16:33:47.537310, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 12 16:33:47 loggia winbindd[1067]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 12 16:33:47 loggia systemd[1]: Started Samba Winbind Daemon. Jan 12 16:33:47 loggia kernel: Key type cifs.spnego registered Jan 12 16:33:47 loggia kernel: Key type cifs.idmap registered Jan 12 16:33:47 loggia 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 16:33:47 loggia kernel: CIFS: Attempting to mount //192.168.178.2/Musikserver Jan 12 16:33:47 loggia nmbd[725]: [2026/01/12 16:33:47.575666, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jan 12 16:33:47 loggia nmbd[725]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.178.3 for name WORKGROUP<1d>. Jan 12 16:33:47 loggia nmbd[725]: This response was from IP 192.168.178.27, reporting an IP address of 192.168.178.27. Jan 12 16:33:47 loggia systemd[1]: Starting Samba SMB Daemon... Jan 12 16:33:47 loggia systemd[1]: apt-daily.service: Succeeded. Jan 12 16:33:47 loggia systemd[1]: Started Daily apt download activities. Jan 12 16:33:47 loggia systemd[1]: Starting Daily apt upgrade and clean activities... Jan 12 16:33:47 loggia smbd[1116]: [2026/01/12 16:33:47.938687, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 12 16:33:47 loggia smbd[1116]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 12 16:33:47 loggia systemd[1]: Started Samba SMB Daemon. Jan 12 16:33:47 loggia systemd[1]: Reached target Multi-User System. Jan 12 16:33:47 loggia systemd[1]: Reached target Graphical Interface. Jan 12 16:33:47 loggia systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 12 16:33:47 loggia systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 12 16:33:47 loggia systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 12 16:33:47 loggia sudo[1076]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:48 loggia systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 12 16:33:48 loggia systemd[1]: Started Daily apt upgrade and clean activities. Jan 12 16:33:48 loggia systemd[1]: Startup finished in 11.834s (kernel) + 25.966s (userspace) = 37.800s. Jan 12 16:33:48 loggia ntfs-3g[1214]: Version 2017.3.23AR.3 integrated FUSE 28 Jan 12 16:33:48 loggia ntfs-3g[1214]: Mounted /dev/sda1 (Read-Write, label "Musikserver", NTFS 3.1) Jan 12 16:33:48 loggia ntfs-3g[1214]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 12 16:33:48 loggia ntfs-3g[1214]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Jan 12 16:33:48 loggia ntfs-3g[1214]: Global ownership and permissions enforced, configuration type 7 Jan 12 16:33:48 loggia sudo[1093]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:48 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:33:48 loggia volumio[994]: info: Loading plugin "volumio_command_line_client"... Jan 12 16:33:48 loggia volumio[994]: info: Loading plugin "upnp"... Jan 12 16:33:48 loggia volumio[994]: info: [1768232028471] Starting Upmpd Daemon Jan 12 16:33:48 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:33:48 loggia volumio[994]: info: Loading plugin "my_music"... Jan 12 16:33:48 loggia volumio[994]: info: Loading plugin "mpd"... Jan 12 16:33:48 loggia volumio[994]: info: Loading plugin "upnp_browser"... Jan 12 16:33:48 loggia volumio-remote-updater[637]: [2026-01-12 16:33:48] [connect] Successful connection Jan 12 16:33:49 loggia volumio[994]: info: Starting UPNP Browser Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "alarm-clock"... Jan 12 16:33:49 loggia volumio[994]: info: Plugin airplay_emulation is not enabled Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "last_100"... Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "webradio"... Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "i2s_dacs"... Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "volumiodiscovery"... Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** For more information see Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 16:33:49 loggia node[994]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:33:49 loggia volumio[994]: *** WARNING *** For more information see Jan 12 16:33:49 loggia node[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:33:49 loggia node[994]: *** WARNING *** For more information see Jan 12 16:33:49 loggia node[994]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 16:33:49 loggia node[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 16:33:49 loggia node[994]: *** WARNING *** For more information see Jan 12 16:33:49 loggia volumio[994]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 12 16:33:49 loggia volumio[994]: info: Discovery: Started advertising with name: Loggia Jan 12 16:33:49 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "soundcloud"... Jan 12 16:33:49 loggia volumio[994]: info: Loading plugin "spop"... Jan 12 16:33:50 loggia volumio[994]: info: Plugin squeezelite_mc is not enabled Jan 12 16:33:50 loggia volumio[994]: info: Loading plugin "youtube2"... Jan 12 16:33:50 loggia sudo[1047]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:52 loggia volumio[994]: info: Plugin ytcr is not enabled Jan 12 16:33:52 loggia volumio[994]: info: Loading plugin "outputs"... Jan 12 16:33:52 loggia volumio[994]: info: Loading plugin "albumart"... Jan 12 16:33:52 loggia volumio[994]: info: Plugin example_plugin is not enabled Jan 12 16:33:52 loggia volumio[994]: info: Loading plugin "inputs"... Jan 12 16:33:52 loggia volumio[994]: info: Loading plugin "updater_comm"... Jan 12 16:33:53 loggia volumio[994]: info: Plugin mpdemulation is not enabled Jan 12 16:33:53 loggia volumio[994]: info: Loading plugin "rest_api"... Jan 12 16:33:53 loggia volumio[994]: info: Loading plugin "websocket"... Jan 12 16:33:53 loggia volumio[994]: info: Starting Socket.io Server version 2.3.0 Jan 12 16:33:53 loggia volumio[994]: info: Loading plugin "fusiondsp"... Jan 12 16:33:53 loggia volumio[994]: Forking 3 albumart workers Jan 12 16:33:53 loggia volumio[994]: info: Applying required configuration parameters for plugin fusiondsp Jan 12 16:33:53 loggia volumio[994]: info: Loading plugin "Systeminfo"... Jan 12 16:33:53 loggia volumio[994]: Starting albumart workers Jan 12 16:33:53 loggia volumio[994]: Starting albumart workers Jan 12 16:33:53 loggia volumio[994]: Starting albumart workers Jan 12 16:33:54 loggia volumio[994]: info: Loading i18n strings for locale de Jan 12 16:33:54 loggia volumio[994]: Updating browse sources language Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::initPlayerControls Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:33:54 loggia volumio[994]: Express server listening on port 3000 Jan 12 16:33:54 loggia volumio[994]: [Metrics] WebUI: 9s 638.02ms Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::resetVolumioState Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::getcurrentVolume Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 16:33:54 loggia volumio[994]: info: Volumio Network Manager: Network status updated: 2 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: Reloading queue from file Jan 12 16:33:54 loggia volumio[994]: info: VolumeController:: Volume=50 Mute =false Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::pushState Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioPushState Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::updateTrackBlock Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrackBlock Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::setRepeat null single undefined Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::pushState Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioPushState Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::setRandom null Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::pushState Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioPushState Jan 12 16:33:54 loggia volumio[994]: info: Setting Device type: Raspberry PI Jan 12 16:33:54 loggia volumio[994]: info: Completed loading Core Plugins Jan 12 16:33:54 loggia volumio[994]: info: Preparing to generate the ALSA configuration file Jan 12 16:33:54 loggia volumio[994]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 12 16:33:54 loggia volumio[994]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03111 Jan 12 16:33:54 loggia volumio[994]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 12 16:33:54 loggia volumio[994]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 12 16:33:54 loggia volumio[994]: info: Reading ALSA contributions from plugins. Jan 12 16:33:54 loggia volumio[994]: info: Asound.conf file unchanged, so no further update is needed Jan 12 16:33:54 loggia volumio[994]: info: Output device has changed, restarting MPD Jan 12 16:33:54 loggia sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:33:54 loggia sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia volumio[994]: info: ___________ START PLUGINS ___________ Jan 12 16:33:54 loggia sudo[1282]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:54 loggia volumio[994]: info: ControllerMpd::onStart: Initializing MPD Jan 12 16:33:54 loggia volumio[994]: info: Creating MPD Configuration file Jan 12 16:33:54 loggia sudo[1284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:33:54 loggia sudo[1284]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia sudo[1288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:33:54 loggia sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia volumio[994]: info: [1768232034591] CoreMusicLibrary::Adding element Medienserver Jan 12 16:33:54 loggia sudo[1288]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia sudo[1290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:33:54 loggia sudo[1290]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia volumio[994]: info: UPNP Browser: Client initialized successfully Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:33:54 loggia volumio[994]: info: [1768232034613] CoreMusicLibrary::Adding element Last_100 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:33:54 loggia volumio[994]: info: [1768232034615] CoreMusicLibrary::Adding element Webradio Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:33:54 loggia volumio[994]: info: Initializing BBC Radios Jan 12 16:33:54 loggia systemd[1]: Listening on mpd.socket. Jan 12 16:33:54 loggia systemd[1]: Starting Music Player Daemon... Jan 12 16:33:54 loggia systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 12 16:33:54 loggia systemd[1]: mpd.service: Succeeded. Jan 12 16:33:54 loggia systemd[1]: Stopped Music Player Daemon. Jan 12 16:33:54 loggia systemd[1]: Starting Music Player Daemon... Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:33:54 loggia volumio[994]: info: [1768232034686] CoreMusicLibrary::Adding element SoundCloud Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia volumio[994]: Cannot find translation for source SoundCloud Jan 12 16:33:54 loggia volumio[994]: info: Creating Spotify config file Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia sudo[1305]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 16:33:54 loggia sudo[1305]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia sudo[1305]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 16:33:54 loggia sudo[1305]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 16:33:54 loggia volumio[994]: info: [1768232034760] CoreMusicLibrary::Adding element YouTube2 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 16:33:54 loggia volumio[994]: Cannot find translation for source SoundCloud Jan 12 16:33:54 loggia volumio[994]: Cannot find translation for source YouTube2 Jan 12 16:33:54 loggia volumio[994]: info: Loading i18n strings for locale de Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: FusionDsp - mixtype--------------------- Hardware Jan 12 16:33:54 loggia volumio[994]: info: Volumio Calling Home Jan 12 16:33:54 loggia volumio[994]: info: Preparing to generate the ALSA configuration file Jan 12 16:33:54 loggia volumio[994]: info: Discovery: adding b0646dff-a9ba-4f35-b18f-ffa162b909b3 Jan 12 16:33:54 loggia volumio[994]: info: Discovery: Found device Loggia Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioGetState Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:54 loggia volumio[994]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 12 16:33:54 loggia volumio[994]: info: Reading ALSA contributions from plugins. Jan 12 16:33:54 loggia volumio[994]: info: MPD Permissions set Jan 12 16:33:54 loggia volumio[994]: info: MPD Permissions set Jan 12 16:33:54 loggia volumio[994]: info: VolumeController:: Volume=50 Mute =false Jan 12 16:33:54 loggia volumio[994]: info: CoreStateMachine::pushState Jan 12 16:33:54 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::volumioPushState Jan 12 16:33:54 loggia volumio[994]: info: Spotify config file written Jan 12 16:33:54 loggia sudo[1312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 12 16:33:54 loggia sudo[1312]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:54 loggia volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 12 16:33:54 loggia volumio[994]: info: No need to fix Spotify hosts Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:33:54 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia systemd[1]: Started go-librespot Daemon. Jan 12 16:33:55 loggia go-librespot[1318]: go-librespot daemon starting... Jan 12 16:33:55 loggia sudo[1312]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:55 loggia volumio[994]: info: Volumio called home Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::volumioGetState Jan 12 16:33:55 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:33:55 loggia systemd[1]: systemd-fsckd.service: Succeeded. Jan 12 16:33:55 loggia volumio[994]: info: Asound.conf file unchanged, so no further update is needed Jan 12 16:33:55 loggia volumio[994]: info: Output device has changed, restarting MPD Jan 12 16:33:55 loggia sudo[1329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 16:33:55 loggia sudo[1332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 16:33:55 loggia sudo[1329]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:55 loggia sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:55 loggia sudo[1329]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:55 loggia volumio[994]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 12 16:33:55 loggia volumio[994]: info: MPD Permissions set Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 12 16:33:55 loggia systemd[1]: mpd.service: Succeeded. Jan 12 16:33:55 loggia systemd[1]: Stopped Music Player Daemon. Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 16:33:55 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:55 loggia systemd[1]: Starting Music Player Daemon... Jan 12 16:33:55 loggia sudo[1336]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 16:33:55 loggia sudo[1336]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:55 loggia sudo[1336]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Jan 12 16:33:55 loggia sudo[1336]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=info msg="running go-librespot 0.4.0" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=debug msg="app state loaded" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=debug msg="stored credentials not found" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 16:33:55 loggia sh[529]: timed out Jan 12 16:33:55 loggia dhcpcd[578]: timed out Jan 12 16:33:55 loggia sh[529]: dhcpcd exited Jan 12 16:33:55 loggia dhcpcd[578]: dhcpcd exited Jan 12 16:33:55 loggia sh[529]: ifup: failed to bring up eth0 Jan 12 16:33:55 loggia systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:33:55 loggia systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 12 16:33:55 loggia go-librespot[1318]: time="2026-01-12T16:33:55+01:00" level=info msg="zeroconf server listening on port 38749" Jan 12 16:33:56 loggia mpd[1341]: Jan 12 16:33 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 16:33:56 loggia volumio[994]: info: camilladsp service started and running in background, instance 1 Jan 12 16:33:56 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp loaded Jan 12 16:33:56 loggia volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 12 16:33:56 loggia systemd[1]: Started Music Player Daemon. Jan 12 16:33:56 loggia sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 12 16:33:56 loggia sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:56 loggia sudo[1290]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:56 loggia sudo[1284]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 12 16:33:56 loggia volumio[994]: info: Adding Signal Path Element [object Object] Jan 12 16:33:56 loggia volumio[994]: info: Adding fusiondspeq DSP Signal Path Element Jan 12 16:33:56 loggia sudo[1332]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp - ---- installed callbackRead Jan 12 16:33:56 loggia volumio[994]: info: Completed starting Core Plugins Jan 12 16:33:56 loggia volumio[994]: info: ------------------------------------------- Jan 12 16:33:56 loggia volumio[994]: info: ----- MyVolumio plugins startup ---- Jan 12 16:33:56 loggia volumio[994]: info: ------------------------------------------- Jan 12 16:33:56 loggia volumio[994]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 12 16:33:56 loggia volumio[994]: info: FusionDsp - Effects disabled Jan 12 16:33:56 loggia volumio[994]: info: MPD running with PID1341 Jan 12 16:33:56 loggia volumio[994]: ,establishing connection Jan 12 16:33:56 loggia systemd[1]: Started FusionDsp Daemon. Jan 12 16:33:57 loggia sudo[1355]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:57 loggia volumio[994]: error: MPD error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: error: MPD error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: error: MPD error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: error: The expression evaluated to a falsy value: Jan 12 16:33:57 loggia volumio[994]: assert.ok(self.idling) Jan 12 16:33:57 loggia volumio[994]: 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 16:33:57 loggia volumio[994]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 12 16:33:57 loggia volumio[994]: error: updateQueue error: null Jan 12 16:33:57 loggia volumio[1361]: Traceback (most recent call last): Jan 12 16:33:57 loggia volumio[1361]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jan 12 16:33:57 loggia volumio[1361]: from aiohttp import web Jan 12 16:33:57 loggia volumio[1361]: ModuleNotFoundError: No module named 'aiohttp' Jan 12 16:33:57 loggia systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:33:57 loggia systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jan 12 16:33:57 loggia go-librespot[1318]: time="2026-01-12T16:33:57+01:00" level=debug msg="obtained new client token: AACtyuOL9et1rJZdurlhfghPIRXk/hVw8AfaZRLZbzqLlhHILkhthB1YrXaDdoguZYGCil+ltX/D0cyyvIpy1xh7qaMrt3Hz3gwl7cEAEHrjOOV4QThXGrW+3yea7vd9rG5pJPx1NIqy+OgcD0VdqDHd7LTeEgvmj9UsoPZdwo7OjIN0o0GXRwM53WlXmXCM05mQeVOhLkj/cZ9fW9i3Qsvg9zaZ49TgsLgQ1xtu6g3B2CB/hRuSda2BIFhd" Jan 12 16:33:58 loggia volumio[994]: info: go-librespot daemon successfully initialized Jan 12 16:33:58 loggia go-librespot[1318]: time="2026-01-12T16:33:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 12 16:33:58 loggia sudo[1384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 16:33:58 loggia sudo[1384]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:58 loggia sudo[1384]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:58 loggia sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 16:33:58 loggia sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:58 loggia sudo[1386]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:58 loggia sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 12 16:33:58 loggia sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:58 loggia systemd[1]: Started UPnP Renderer front-end to MPD. Jan 12 16:33:58 loggia sudo[1390]: pam_unix(sudo:session): session closed for user root Jan 12 16:33:58 loggia volumio[994]: info: Upmpdcli Daemon Started Jan 12 16:33:58 loggia volumio[1392]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 12 16:33:59 loggia systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jan 12 16:33:59 loggia systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 1. Jan 12 16:33:59 loggia systemd[1]: Stopped FusionDsp Daemon. Jan 12 16:33:59 loggia systemd[1]: Started FusionDsp Daemon. Jan 12 16:33:59 loggia volumio[1408]: Traceback (most recent call last): Jan 12 16:33:59 loggia volumio[1408]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jan 12 16:33:59 loggia volumio[1408]: from aiohttp import web Jan 12 16:33:59 loggia volumio[1408]: ModuleNotFoundError: No module named 'aiohttp' Jan 12 16:33:59 loggia systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:33:59 loggia systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jan 12 16:33:59 loggia sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 16:33:59 loggia sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:59 loggia sudo[1413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 16:33:59 loggia sudo[1413]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:33:59 loggia sudo[1416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 16:33:59 loggia sudo[1416]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 16:34:00 loggia systemd[1]: Started MPD Monitor Service. Jan 12 16:34:00 loggia mpd_monitor.sh[1417]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 16:34:00 loggia sudo[1410]: pam_unix(sudo:session): session closed for user root Jan 12 16:34:00 loggia volumio[994]: info: Successfully started MPD Monitor Jan 12 16:34:00 loggia systemd[1]: Stopping MPD Monitor Service... Jan 12 16:34:00 loggia systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Jan 12 16:34:00 loggia systemd[1]: mpd_monitor.service: Succeeded. Jan 12 16:34:00 loggia systemd[1]: Stopped MPD Monitor Service. Jan 12 16:34:00 loggia systemd[1]: Started MPD Monitor Service. Jan 12 16:34:00 loggia sudo[1416]: pam_unix(sudo:session): session closed for user root Jan 12 16:34:00 loggia mpd_monitor.sh[1421]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 16:34:00 loggia sudo[1413]: pam_unix(sudo:session): session closed for user root Jan 12 16:34:00 loggia volumio[994]: info: Successfully started MPD Monitor Jan 12 16:34:00 loggia volumio[994]: info: Successfully started MPD Monitor Jan 12 16:34:01 loggia volumio[994]: info: Initializing connection to go-librespot Websocket Jan 12 16:34:01 loggia volumio[994]: info: Connection to go-librespot Websocket established Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=debug msg="new websocket client" Jan 12 16:34:01 loggia systemd[1]: fusiondsp.service: Service RestartSec=2s expired, scheduling restart. Jan 12 16:34:01 loggia systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 2. Jan 12 16:34:01 loggia systemd[1]: Stopped FusionDsp Daemon. Jan 12 16:34:01 loggia systemd[1]: Started FusionDsp Daemon. Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=debug msg="completed keyexchange" Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=debug msg="completed challenge" Jan 12 16:34:01 loggia volumio[1425]: Traceback (most recent call last): Jan 12 16:34:01 loggia volumio[1425]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 1, in Jan 12 16:34:01 loggia volumio[1425]: from aiohttp import web Jan 12 16:34:01 loggia volumio[1425]: ModuleNotFoundError: No module named 'aiohttp' Jan 12 16:34:01 loggia systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Jan 12 16:34:01 loggia systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=info msg="authenticated AP" username="vg*********************np" Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=info msg="authenticated Login5" username="vg*********************np" Jan 12 16:34:01 loggia go-librespot[1318]: time="2026-01-12T16:34:01+01:00" level=info msg="accepted zeroconf from S25 Edge von Kurt" username="vg*********************np" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="dealer connection opened" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="starting accesspoint recv loop" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="starting dealer recv loop" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="received accesspoint ping" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="received connection id: NzZlNmU0OTAtYmY4...MDlCNzg2ODA1Rg==" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="received accesspoint pong ack" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="handling transfer player command from df3c247884ccb6bd949cbdebd40d3cfbf3c991f8" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="resolved context of track" uri="spotify:album:1U314gpHouXftVpPa0raUD" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="fetched new page 0 with 12 items (list: 12)" uri="spotify:album:1U314gpHouXftVpPa0raUD" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="loading track (paused: false, position: 983ms)" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="emitting websocket event: will_play" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=warning msg="original track has no formats, alternatives have a total of 4" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="selected format OGG_VORBIS_320 (0a20337218e827149abda44af1be6906a79a045f)" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="requested aes key for file 0a20337218e827149abda44af1be6906a79a045f, gid: 60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 415" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1705" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia volumio[994]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:1U314gpHouXftVpPa0raUD","uri":"spotify:track:60mX5pLCkMlksbiU7qKLRp","play_origin":""}} Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="fetched first chunk of 19, total size is 9791147 bytes" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="seek to 983ms (diff: 983ms, samples: 43350, bytes: 0)" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="created new output device" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=info msg="loaded track \"Eine Insel mit zwei Bergen\" (paused: false, position: 983ms, duration: 226693ms, prefetched: false)" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 12 16:34:02 loggia volumio[994]: info: camilladsp stopping service pid 1351... Jan 12 16:34:02 loggia volumio[994]: info: camilladsp service terminated, instance 1 Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - Effects disabled Jan 12 16:34:02 loggia volumio[994]: info: camilladsp service started and running in background, instance 1 Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 12 16:34:02 loggia volumio[994]: info: FusionDsp - Effects disabled Jan 12 16:34:02 loggia volumio[994]: error: FusionDsp - WebSocket error: [object Object] Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="scheduling prefetch in 196s" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="emitting websocket event: metadata" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="emitting websocket event: active" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="sending successful reply for dealer request" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 12 16:34:02 loggia volumio[994]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:60mX5pLCkMlksbiU7qKLRp","name":"Eine Insel mit zwei Bergen","artist_names":["Dolls United"],"album_name":"Gut gebrüllt!","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028f7eddd74a6ecba30762bd5d","position":983,"duration":226693,"release_date":"year:2024 month:12 day:20","track_number":1,"disc_number":1}} Jan 12 16:34:02 loggia volumio[994]: SPOTIFY: received: {"type":"active","data":null} Jan 12 16:34:02 loggia volumio[994]: info: Aligning Spotify Volume to Volumio Volume Jan 12 16:34:02 loggia volumio[994]: info: CoreCommandRouter::volumioGetState Jan 12 16:34:02 loggia volumio[994]: info: CorePlayQueue::getTrack 0 Jan 12 16:34:02 loggia volumio[994]: info: Setting Spotify Volume from Volumio: 50 Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 16:34:02 loggia go-librespot[1318]: time="2026-01-12T16:34:02+01:00" level=trace msg="emitting websocket event: playing" Jan 12 16:34:02 loggia volumio[994]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:1U314gpHouXftVpPa0raUD","uri":"spotify:track:60mX5pLCkMlksbiU7qKLRp","resume":false,"play_origin":""}} Jan 12 16:34:02 loggia volumio[994]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 16:34:02 loggia volumio[994]: TypeError: Cannot read property 'service' of undefined Jan 12 16:34:02 loggia volumio[994]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Jan 12 16:34:02 loggia volumio[994]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Jan 12 16:34:02 loggia volumio[994]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Jan 12 16:34:02 loggia volumio[994]: at WebSocket.emit (events.js:315:20) Jan 12 16:34:02 loggia volumio[994]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jan 12 16:34:02 loggia volumio[994]: at Receiver.emit (events.js:315:20) Jan 12 16:34:02 loggia volumio[994]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jan 12 16:34:02 loggia volumio[994]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jan 12 16:34:02 loggia volumio[994]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jan 12 16:34:02 loggia volumio[994]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jan 12 16:34:02 loggia volumio[994]: at writeOrBuffer (internal/streams/writable.js:358:12) Jan 12 16:34:02 loggia volumio[994]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jan 12 16:34:02 loggia volumio[994]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jan 12 16:34:02 loggia volumio[994]: at Socket.emit (events.js:315:20) Jan 12 16:34:02 loggia volumio[994]: at addChunk (internal/streams/readable.js:309:12) Jan 12 16:34:02 loggia volumio[994]: at readableAddChunk (internal/streams/readable.js:284:9) Jan 12 16:34:02 loggia volumio[994]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 16:34:03 loggia go-librespot[1318]: time="2026-01-12T16:34:03+01:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:03 loggia go-librespot[1318]: time="2026-01-12T16:34:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1298" Jan 12 16:34:03 loggia go-librespot[1318]: time="2026-01-12T16:34:03+01:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:60mX5pLCkMlksbiU7qKLRp" Jan 12 16:34:03 loggia sudo[1446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-12 16:33 Jan 12 16:34:03 loggia sudo[1446]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"