-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Sun 2025-12-14 08:16:00 UTC. -- Dec 14 08:15:45 hifi systemd-timedated[1256]: Changed local time to Sun Dec 14 08:15:45 2025 Dec 14 08:15:45 hifi sudo[1252]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:45 hifi volumio-time-update[657]: volumio-time-update-util: System time updated successfully. Dec 14 08:15:45 hifi systemd[1]: Started Volumio Time Update Utility. Dec 14 08:15:45 hifi systemd[1]: Reached target Multi-User System. Dec 14 08:15:45 hifi systemd[1]: Reached target Graphical Interface. Dec 14 08:15:45 hifi systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 14 08:15:45 hifi systemd[1]: Starting Daily apt download activities... Dec 14 08:15:45 hifi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 14 08:15:45 hifi systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "network"... Dec 14 08:15:46 hifi volumio[1216]: info: Refreshing Cached IP Addresses Dec 14 08:15:46 hifi sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 14 08:15:46 hifi sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:46 hifi sudo[1282]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:46 hifi sudo[1284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 14 08:15:46 hifi sudo[1284]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:46 hifi sudo[1284]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "services"... Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "alsa_controller"... Dec 14 08:15:46 hifi sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 14 08:15:46 hifi sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:46 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "wizard"... Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "networkfs"... Dec 14 08:15:46 hifi volumio[1216]: info: Starting Udev Watcher for removable devices Dec 14 08:15:46 hifi sudo[1308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=jagardu,password=Xmt74001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=1.0 //192.168.0.1/sda1 /mnt/NAS/test Dec 14 08:15:46 hifi sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:46 hifi volumio[1216]: info: Ignoring mount for partition: boot Dec 14 08:15:46 hifi volumio[1216]: info: Ignoring mount for partition: volumio Dec 14 08:15:46 hifi volumio[1216]: info: Ignoring mount for partition: volumio_data Dec 14 08:15:46 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "volumio_command_line_client"... Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "upnp"... Dec 14 08:15:46 hifi volumio[1216]: info: [1765700146584] Starting Upmpd Daemon Dec 14 08:15:46 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "my_music"... Dec 14 08:15:46 hifi volumio[1216]: info: Loading plugin "mpd"... Dec 14 08:15:46 hifi volumio-remote-updater[669]: [2025-12-14 08:15:46] [connect] Successful connection Dec 14 08:15:46 hifi kernel: Key type cifs.spnego registered Dec 14 08:15:46 hifi kernel: Key type cifs.idmap registered Dec 14 08:15:46 hifi kernel: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Dec 14 08:15:46 hifi kernel: CIFS: VFS: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Dec 14 08:15:46 hifi kernel: CIFS: Attempting to mount //192.168.0.1/sda1 Dec 14 08:15:46 hifi sudo[1308]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:46 hifi kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 14 08:15:46 hifi kernel: CIFS: VFS: cifs_mount failed w/return code = -111 Dec 14 08:15:47 hifi volumio[1216]: info: Loading plugin "upnp_browser"... Dec 14 08:15:47 hifi volumio[1216]: info: Loading plugin "alarm-clock"... Dec 14 08:15:47 hifi volumio[1216]: info: Loading plugin "airplay_emulation"... Dec 14 08:15:47 hifi volumio[1216]: info: Starting Shairport Sync Dec 14 08:15:47 hifi volumio[1216]: info: Loading plugin "last_100"... Dec 14 08:15:47 hifi volumio[1216]: info: Loading plugin "webradio"... Dec 14 08:15:48 hifi volumio[1216]: info: Loading plugin "i2s_dacs"... Dec 14 08:15:48 hifi volumio[1216]: info: Loading plugin "volumiodiscovery"... Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** For more information see Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 14 08:15:48 hifi node[1216]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 14 08:15:48 hifi volumio[1216]: *** WARNING *** For more information see Dec 14 08:15:48 hifi node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 14 08:15:48 hifi node[1216]: *** WARNING *** For more information see Dec 14 08:15:48 hifi node[1216]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 14 08:15:48 hifi node[1216]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 14 08:15:48 hifi node[1216]: *** WARNING *** For more information see Dec 14 08:15:48 hifi volumio[1216]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 14 08:15:48 hifi volumio[1216]: info: Discovery: Started advertising with name: Hifi Dec 14 08:15:48 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 14 08:15:48 hifi volumio[1216]: info: Loading plugin "spop"... Dec 14 08:15:48 hifi systemd[1]: apt-daily.service: Succeeded. Dec 14 08:15:48 hifi systemd[1]: Started Daily apt download activities. Dec 14 08:15:48 hifi systemd[1]: Starting Daily apt upgrade and clean activities... Dec 14 08:15:49 hifi sudo[1293]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:49 hifi volumio[1216]: info: Plugin now_playing is not enabled Dec 14 08:15:49 hifi volumio[1216]: info: Loading plugin "outputs"... Dec 14 08:15:49 hifi volumio[1216]: info: Loading plugin "albumart"... Dec 14 08:15:49 hifi volumio[1216]: info: Plugin example_plugin is not enabled Dec 14 08:15:49 hifi volumio[1216]: info: Loading plugin "inputs"... Dec 14 08:15:49 hifi volumio[1216]: info: Loading plugin "updater_comm"... Dec 14 08:15:50 hifi volumio[1216]: info: Plugin mpdemulation is not enabled Dec 14 08:15:50 hifi volumio[1216]: info: Loading plugin "rest_api"... Dec 14 08:15:50 hifi volumio[1216]: info: Loading plugin "websocket"... Dec 14 08:15:50 hifi volumio[1216]: info: Starting Socket.io Server version 2.3.0 Dec 14 08:15:50 hifi volumio[1216]: info: Loading plugin "fusiondsp"... Dec 14 08:15:50 hifi volumio[1216]: Forking 3 albumart workers Dec 14 08:15:50 hifi systemd[1]: apt-daily-upgrade.service: Succeeded. Dec 14 08:15:50 hifi systemd[1]: Started Daily apt upgrade and clean activities. Dec 14 08:15:50 hifi systemd[1]: Startup finished in 13.249s (kernel) + 41.588s (userspace) = 54.838s. Dec 14 08:15:50 hifi volumio[1216]: info: Applying required configuration parameters for plugin fusiondsp Dec 14 08:15:50 hifi volumio[1216]: info: Plugin mpd_oled is not enabled Dec 14 08:15:51 hifi volumio[1216]: info: Loading i18n strings for locale sv Dec 14 08:15:51 hifi volumio[1216]: Updating browse sources language Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 08:15:51 hifi volumio[1216]: Starting albumart workers Dec 14 08:15:51 hifi volumio[1216]: Starting albumart workers Dec 14 08:15:51 hifi volumio[1216]: Starting albumart workers Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::initPlayerControls Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 14 08:15:51 hifi volumio[1216]: Express server listening on port 3000 Dec 14 08:15:51 hifi volumio[1216]: [Metrics] WebUI: 9s 241.02ms Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::resetVolumioState Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::getcurrentVolume Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Dec 14 08:15:51 hifi volumio[1216]: info: Volumio Network Manager: Network status updated: 2 Dec 14 08:15:51 hifi volumio[1216]: info: Cannot mount NAS test at system boot, trial number 1 ,retrying in 5 seconds Dec 14 08:15:51 hifi volumio-remote-updater[669]: [2025-12-14 08:15:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1765700146 101 Dec 14 08:15:51 hifi volumio[1216]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Dec 14 08:15:51 hifi volumio[1216]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:51 hifi volumio[1216]: info: Reloading queue from file Dec 14 08:15:51 hifi volumio[1216]: info: Setting Device type: Raspberry PI Dec 14 08:15:51 hifi volumio[1216]: info: Completed loading Core Plugins Dec 14 08:15:51 hifi volumio[1216]: info: Preparing to generate the ALSA configuration file Dec 14 08:15:51 hifi volumio[1216]: info: VolumeController:: Volume=undefined Mute =false Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::pushState Dec 14 08:15:51 hifi volumio[1216]: info: CorePlayQueue::getTrack 0 Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::volumioPushState Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::updateTrackBlock Dec 14 08:15:51 hifi volumio[1216]: info: CorePlayQueue::getTrackBlock Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::volumioRetrievevolume Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::setRepeat null single undefined Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::pushState Dec 14 08:15:51 hifi volumio[1216]: info: CorePlayQueue::getTrack 0 Dec 14 08:15:51 hifi volumio[1216]: info: CoreCommandRouter::volumioPushState Dec 14 08:15:51 hifi volumio[1216]: info: CoreStateMachine::setRandom null Dec 14 08:15:52 hifi volumio[1216]: info: CoreStateMachine::pushState Dec 14 08:15:52 hifi volumio[1216]: info: CorePlayQueue::getTrack 0 Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::volumioPushState Dec 14 08:15:52 hifi volumio[1216]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 14 08:15:52 hifi volumio[1216]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 14 08:15:52 hifi volumio[1216]: info: Reading ALSA contributions from plugins. Dec 14 08:15:52 hifi volumio[1216]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 14 08:15:52 hifi volumio[1216]: info: Asound.conf file unchanged, so no further update is needed Dec 14 08:15:52 hifi volumio[1216]: info: Output device has changed, restarting MPD Dec 14 08:15:52 hifi volumio[1216]: info: Output device has changed, restarting Shairport Sync Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi sudo[1468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 14 08:15:52 hifi sudo[1468]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi sudo[1468]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:52 hifi sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 14 08:15:52 hifi sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi systemd[1]: Stopping Music Player Daemon... Dec 14 08:15:52 hifi volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 14 08:15:52 hifi volumio[1216]: info: ___________ START PLUGINS ___________ Dec 14 08:15:52 hifi volumio[1216]: info: ControllerMpd::onStart: Initializing MPD Dec 14 08:15:52 hifi volumio[1216]: info: Creating MPD Configuration file Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 14 08:15:52 hifi sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 14 08:15:52 hifi volumio[1216]: info: [1765700152193] CoreMusicLibrary::Adding element Mediaservrar Dec 14 08:15:52 hifi sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 08:15:52 hifi sudo[1477]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:52 hifi sudo[1479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 14 08:15:52 hifi sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi systemd[1]: mpd.service: Succeeded. Dec 14 08:15:52 hifi systemd[1]: Stopped Music Player Daemon. Dec 14 08:15:52 hifi volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 14 08:15:52 hifi volumio[1216]: info: [1765700152331] CoreMusicLibrary::Adding element Last_100 Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 14 08:15:52 hifi volumio[1216]: info: [1765700152334] CoreMusicLibrary::Adding element Webradio Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 14 08:15:52 hifi volumio[1216]: info: Initializing BBC Radios Dec 14 08:15:52 hifi systemd[1]: Starting Music Player Daemon... Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: Creating Spotify config file Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi sudo[1488]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 14 08:15:52 hifi sudo[1488]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi sudo[1488]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:52 hifi volumio[1216]: info: Loading i18n strings for locale sv Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: FusionDsp - mixtype--------------------- undefined Dec 14 08:15:52 hifi volumio[1216]: info: Volumio Calling Home Dec 14 08:15:52 hifi volumio[1216]: info: Preparing to generate the ALSA configuration file Dec 14 08:15:52 hifi volumio[1216]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Dec 14 08:15:52 hifi volumio[1216]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Dec 14 08:15:52 hifi volumio[1216]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 14 08:15:52 hifi volumio[1216]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Dec 14 08:15:52 hifi volumio[1216]: info: Reading ALSA contributions from plugins. Dec 14 08:15:52 hifi volumio[1216]: info: MPD Permissions set Dec 14 08:15:52 hifi volumio[1216]: info: MPD Permissions set Dec 14 08:15:52 hifi volumio[1216]: info: VolumeController:: Volume=undefined Mute =false Dec 14 08:15:52 hifi volumio[1216]: info: CoreStateMachine::pushState Dec 14 08:15:52 hifi volumio[1216]: info: CorePlayQueue::getTrack 0 Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::volumioPushState Dec 14 08:15:52 hifi volumio[1216]: info: Volumio called home Dec 14 08:15:52 hifi volumio[1216]: info: Spotify config file written Dec 14 08:15:52 hifi sudo[1506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 14 08:15:52 hifi sudo[1506]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:52 hifi volumio[1216]: 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 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi systemd[1]: Started go-librespot Daemon. Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:52 hifi go-librespot[1508]: go-librespot daemon starting... Dec 14 08:15:52 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:52 hifi volumio[1216]: info: No need to fix Spotify hosts Dec 14 08:15:52 hifi sudo[1506]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi volumio[1216]: info: Starting Shairport Sync Dec 14 08:15:53 hifi volumio[1216]: info: Starting Shairport Sync Dec 14 08:15:53 hifi volumio[1216]: info: Starting Shairport Sync Dec 14 08:15:53 hifi sudo[1523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 14 08:15:53 hifi sudo[1523]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi sudo[1526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 14 08:15:53 hifi sudo[1526]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 14 08:15:53 hifi systemd[1]: shairport-sync.service: Succeeded. Dec 14 08:15:53 hifi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::volumioGetState Dec 14 08:15:53 hifi volumio[1216]: info: CorePlayQueue::getTrack 0 Dec 14 08:15:53 hifi sudo[1529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 14 08:15:53 hifi sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi volumio[1216]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 14 08:15:53 hifi volumio[1216]: SPOTIFY: BQAQBeiLbb-s_XeywGeIBNyIMYCCqGsNKacvFy_3bh5eLdZr6C-1sk4pnWoiP_CilueMUwmHqqdmlv95QanlJu6n4XHzyr435zl8G5H9KOYLCV2gdXdP5QeRvqXj1dRg_SVMW59BHv-c22p-TiigbWNMADRFEJVkPAjGvuTJ5TYtqlcPiyVD0RMiQcJAaSx_mhiHQm6kQOPQoJaVa6zQGFJwZYRmAeQJi9i3U_n_yJb0ghAVkM_k-DUpae2y0Ox7t208PiRdqlyRMMWGNjRBi1mFa0sid5M5 Dec 14 08:15:53 hifi volumio[1216]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 14 08:15:53 hifi volumio[1216]: info: New Spotify access token = BQAQBeiLbb-s_XeywGeIBNyIMYCCqGsNKacvFy_3bh5eLdZr6C-1sk4pnWoiP_CilueMUwmHqqdmlv95QanlJu6n4XHzyr435zl8G5H9KOYLCV2gdXdP5QeRvqXj1dRg_SVMW59BHv-c22p-TiigbWNMADRFEJVkPAjGvuTJ5TYtqlcPiyVD0RMiQcJAaSx_mhiHQm6kQOPQoJaVa6zQGFJwZYRmAeQJi9i3U_n_yJb0ghAVkM_k-DUpae2y0Ox7t208PiRdqlyRMMWGNjRBi1mFa0sid5M5 Dec 14 08:15:53 hifi volumio[1216]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 14 08:15:53 hifi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi volumio[1216]: info: Asound.conf file unchanged, so no further update is needed Dec 14 08:15:53 hifi volumio[1216]: info: Output device has changed, restarting MPD Dec 14 08:15:53 hifi sudo[1523]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 14 08:15:53 hifi systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 14 08:15:53 hifi systemd[1]: shairport-sync.service: Succeeded. Dec 14 08:15:53 hifi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi volumio[1216]: info: Output device has changed, restarting Shairport Sync Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:53 hifi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi sudo[1526]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi sudo[1529]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi sudo[1534]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 14 08:15:53 hifi sudo[1534]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi sudo[1534]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi sudo[1536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 14 08:15:53 hifi sudo[1536]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi volumio[1216]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 14 08:15:53 hifi systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 14 08:15:53 hifi systemd[1]: mpd.service: Succeeded. Dec 14 08:15:53 hifi systemd[1]: Stopped Music Player Daemon. Dec 14 08:15:53 hifi volumio[1216]: info: MPD Permissions set Dec 14 08:15:53 hifi volumio[1216]: info: Shairport-Sync Started Dec 14 08:15:53 hifi volumio[1216]: Error adding Membership: Error: addMembership EINVAL Dec 14 08:15:53 hifi volumio[1216]: info: Shairport-Sync Started Dec 14 08:15:53 hifi volumio[1216]: info: Shairport-Sync Started Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi systemd[1]: Starting Music Player Daemon... Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:53 hifi volumio[1216]: info: Starting Shairport Sync Dec 14 08:15:53 hifi sudo[1552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 14 08:15:53 hifi sudo[1552]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 14 08:15:53 hifi sudo[1545]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" level=info msg="running go-librespot 0.4.0" Dec 14 08:15:53 hifi systemd[1]: shairport-sync.service: Succeeded. Dec 14 08:15:53 hifi sudo[1545]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:53 hifi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" level=debug msg="app state loaded" Dec 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 14 08:15:53 hifi sudo[1545]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 14 08:15:53 hifi volumio[1216]: SPOTIFY: User informations: {"country":"SE","display_name":"Jonas Olofsson","email":"jonas_olofsson@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jagardu"},"followers":{"href":null,"total":5},"href":"https://api.spotify.com/v1/users/jagardu","id":"jagardu","images":[{"height":300,"url":"https://scontent-tpe1-1.xx.fbcdn.net/v/t39.30808-1/464915069_8503734273008834_546775584982816129_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=104&ccb=1-7&_nc_sid=79bf43&_nc_ohc=GNQ1MxFf84gQ7kNvwFgz_Oz&_nc_oc=AdlgIEZO4fOBBULIXXFFSwZgzy3r7O5MJvbw6aAB6CgYHKg8HS9WkTlLjYpYAkS06O1hndRoM6JwQxyj57-lZPsn&_nc_zt=24&_nc_ht=scontent-tpe1-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MVGjp0eyVxc3xUYefJ3kDw&_nc_tpa=Q5bMBQHwZFdzSX-yaESmRU4KZmjJuwASaB2Qr2yN-mLWCcN_Dvlf165cjhY8awMnEUXLMD7nmxlj&oh=00_Afm3zeGsg1soqG2bvkLJIW3RmTnWShWRGwA3rQjGCTXpGg&oe=694392BD","width":300},{"height":64,"url":"https://scontent-tpe1-1.xx.fbcdn.net/v/t39.30808-1/464915069_8503734273008834_546775584982816129_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=104&ccb=1-7&_nc_sid=28885b&_nc_ohc=GNQ1MxFf84gQ7kNvwFgz_Oz&_nc_oc=AdlgIEZO4fOBBULIXXFFSwZgzy3r7O5MJvbw6aAB6CgYHKg8HS9WkTlLjYpYAkS06O1hndRoM6JwQxyj57-lZPsn&_nc_zt=24&_nc_ht=scontent-tpe1-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MVGjp0eyVxc3xUYefJ3kDw&_nc_tpa=Q5bMBQEBf0WwY1zQFxcOdAr8OBVIah93p0KsYutJEf9IdmCOhyXC1zBuVYhd7yleQ9QliF7TjPSA&oh=00_AfliO3Y5YHjpfhbBZcYf57dAHm5P9z-brauDqZbKhBzHRg&oe=694392BD","width":64}],"product":"premium","type":"user","uri":"spotify:user:jagardu"} Dec 14 08:15:53 hifi volumio[1216]: info: Spotify Successfully logged in Dec 14 08:15:53 hifi sudo[1552]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 14 08:15:53 hifi volumio[1216]: info: [1765700153662] CoreMusicLibrary::Adding element Spotify Dec 14 08:15:53 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 14 08:15:53 hifi volumio[1216]: Cannot find translation for source Spotify Dec 14 08:15:53 hifi volumio[1216]: info: Shairport-Sync Started Dec 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" 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 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" 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 14 08:15:53 hifi go-librespot[1508]: time="2025-12-14T08:15:53Z" 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 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=info msg="zeroconf server listening on port 42553" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="obtained new client token: AABmNv0K4inNweQ4LR+iH5gL16wbmSNZN/Ap2YvAdJ/PIFFHsHMKDU+w0s4e0XxJyN80xe+CABadf6bMbeyeP3QPH2A+tBATf59OcOUo2Ail8IT6E51G6eSsy4AUtfl1FB4GxqqDSTkl1roWdP+rGPVmIFxHk/E/iF/anu34winw1uKTH/n4LGs9qlEDaPigMjhS4jYbLoTH8f6WvgSLLn0GQDaAb5J9LLVfPKMA7LIXz0Zz8L3gqg==" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="completed keyexchange" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="completed challenge" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=info msg="authenticated AP" username="ja***du" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=info msg="authenticated Login5" username="ja***du" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="initializing zeroconf session" username="ja***du" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="dealer connection opened" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=trace msg="starting accesspoint recv loop" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=trace msg="starting dealer recv loop" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=trace msg="received accesspoint ping" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="received connection id: N2JhOGUzZWMtOGIx...REFBRDY3RDY5Nw==" Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=trace msg="received accesspoint pong ack" Dec 14 08:15:54 hifi volumio[1216]: info: camilladsp spawned new process with pid 1567, instance 1, run: true Dec 14 08:15:54 hifi volumio[1216]: info: camilladsp service started and running in background, instance 1 Dec 14 08:15:54 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 14 08:15:54 hifi volumio[1216]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Dec 14 08:15:54 hifi volumio[1216]: info: FusionDsp loaded Dec 14 08:15:54 hifi volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 14 08:15:54 hifi sudo[1571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Dec 14 08:15:54 hifi sudo[1571]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:54 hifi go-librespot[1508]: time="2025-12-14T08:15:54Z" level=debug msg="put connect state because NEW_DEVICE" Dec 14 08:15:54 hifi volumio[1216]: info: FusionDsp - Reporting Fusion DSP Enabled Dec 14 08:15:54 hifi volumio[1216]: info: Adding Signal Path Element [object Object] Dec 14 08:15:54 hifi volumio[1216]: info: Adding fusiondspeq DSP Signal Path Element Dec 14 08:15:54 hifi volumio[1216]: info: FusionDsp - ---- installed callbackRead Dec 14 08:15:54 hifi volumio[1216]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 14 08:15:54 hifi volumio[1216]: error: FusionDsp - WebSocket error: [object Object] Dec 14 08:15:54 hifi volumio[1216]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 14 08:15:54 hifi systemd[1]: Started FusionDsp Daemon. Dec 14 08:15:54 hifi sudo[1571]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:55 hifi mpd[1556]: Dec 14 08:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 14 08:15:55 hifi systemd[1]: Started Music Player Daemon. Dec 14 08:15:55 hifi sudo[1536]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:55 hifi sudo[1479]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:55 hifi sudo[1470]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:55 hifi volumio[1216]: info: Completed starting Core Plugins Dec 14 08:15:55 hifi volumio[1216]: info: ------------------------------------------- Dec 14 08:15:55 hifi volumio[1216]: info: ----- MyVolumio plugins startup ---- Dec 14 08:15:55 hifi volumio[1216]: info: ------------------------------------------- Dec 14 08:15:55 hifi volumio[1216]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 14 08:15:55 hifi volumio[1216]: info: MPD running with PID1556 Dec 14 08:15:55 hifi volumio[1216]: ,establishing connection Dec 14 08:15:55 hifi volumio[1216]: error: MPD error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: MPD error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: MPD error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: The expression evaluated to a falsy value: Dec 14 08:15:55 hifi volumio[1216]: assert.ok(self.idling) Dec 14 08:15:55 hifi volumio[1216]: error: updateQueue error: null Dec 14 08:15:56 hifi volumio[1216]: info: go-librespot daemon successfully initialized Dec 14 08:15:56 hifi sudo[1599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=jagardu,password=Xmt74001,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=1.0 //192.168.0.1/sda1 /mnt/NAS/test Dec 14 08:15:56 hifi sudo[1599]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:56 hifi sudo[1601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 14 08:15:56 hifi sudo[1601]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:56 hifi kernel: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Dec 14 08:15:56 hifi kernel: CIFS: VFS: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Dec 14 08:15:56 hifi kernel: CIFS: Attempting to mount //192.168.0.1/sda1 Dec 14 08:15:56 hifi kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 14 08:15:56 hifi kernel: CIFS: VFS: cifs_mount failed w/return code = -111 Dec 14 08:15:56 hifi sudo[1601]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:56 hifi sudo[1599]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:56 hifi sudo[1605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 14 08:15:56 hifi sudo[1605]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:56 hifi volumio[1216]: info: Cannot mount NAS test at system boot, trial number 2 ,retrying in 5 seconds Dec 14 08:15:56 hifi sudo[1605]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:56 hifi sudo[1610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 14 08:15:56 hifi sudo[1610]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:15:56 hifi sudo[1610]: pam_unix(sudo:session): session closed for user root Dec 14 08:15:56 hifi systemd[1]: Started UPnP Renderer front-end to MPD. Dec 14 08:15:56 hifi volumio[1216]: info: Upmpdcli Daemon Started Dec 14 08:15:56 hifi volumio[1612]: Generating RSA private key, 4096 bit long modulus (2 primes) Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="handling transfer player command from 874f56acbd27f0601c865e5c18c7a291529ba37f" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="resolved context of track" uri="spotify:playlist:7EAoJP31PjLvpWjjhnqyNA" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=trace msg="fetched new page 0 with 265 items (list: 265)" uri="spotify:playlist:7EAoJP31PjLvpWjjhnqyNA" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="loading track (paused: true, position: 225269ms)" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=trace msg="emitting websocket event: will_play" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="selected format OGG_VORBIS_320 (606e853a0390142041d04705a2131bb0ee843417)" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="requested aes key for file 606e853a0390142041d04705a2131bb0ee843417, gid: 0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3511" Dec 14 08:15:57 hifi go-librespot[1508]: time="2025-12-14T08:15:57Z" level=trace msg="found 2 cdn urls" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="fetched first chunk of 18, total size is 9249668 bytes" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2198" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="fetched chunk 17/17, size: 336772" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=trace msg="seek to 225269ms (diff: 148ms, samples: 9934362, bytes: 9208494)" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="created new output device" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=info msg="loaded track \"King\" (paused: true, position: 225269ms, duration: 226170ms, prefetched: false)" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=trace msg="emitting websocket event: metadata" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=trace msg="emitting websocket event: active" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="sending successful reply for dealer request" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=trace msg="emitting websocket event: paused" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="handling resume player command from 874f56acbd27f0601c865e5c18c7a291529ba37f" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=trace msg="seek to 225269ms (diff: 148ms, samples: 9934362, bytes: 9208494)" uri="spotify:track:0MV8y9fwHTp4GNAh3reZ4S" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" 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" Dec 14 08:15:58 hifi go-librespot[1508]: time="2025-12-14T08:15:58Z" level=debug msg="resume track at 225121ms" Dec 14 08:15:58 hifi volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Dec 14 08:15:58 hifi volumio[1216]: info: FusionDsp - ---- read samplerate from file: 44100 Dec 14 08:15:58 hifi volumio[1216]: info: camilladsp stopping service pid 1567... Dec 14 08:15:58 hifi volumio[1216]: info: camilladsp service terminated, instance 1 Dec 14 08:15:58 hifi volumio[1216]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 14 08:15:58 hifi volumio[1216]: info: camilladsp service started and running in background, instance 1 Dec 14 08:15:58 hifi volumio[1216]: info: camilladsp spawned new process with pid 1631, instance 1, run: true Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="sending successful reply for dealer request" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="prefetching next track" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="selected format OGG_VORBIS_320 (c93e7a95b6c292046da2997b22bebb0fc94f0f0a)" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="requested aes key for file c93e7a95b6c292046da2997b22bebb0fc94f0f0a, gid: 0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="emitting websocket event: playing" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="emitting websocket event: not_playing" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi volumio[1216]: info: Initializing connection to go-librespot Websocket Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="new websocket client" Dec 14 08:15:59 hifi volumio[1216]: info: Connection to go-librespot Websocket established Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="emitting websocket event: will_play" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="found 2 cdn urls" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi volumio[1216]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:7EAoJP31PjLvpWjjhnqyNA","uri":"spotify:track:0JoNMwglQorgs5Rz2xYK6b","play_origin":"playlist"}} Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="selected format OGG_VORBIS_320 (c93e7a95b6c292046da2997b22bebb0fc94f0f0a)" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="requested aes key for file c93e7a95b6c292046da2997b22bebb0fc94f0f0a, gid: 0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="found 2 cdn urls" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="fetched first chunk of 14, total size is 7070012 bytes" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=info msg="prefetched track \"Through a Glass\" (duration: 180273ms)" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="fetched first chunk of 14, total size is 7070012 bytes" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Dec 14 08:15:59 hifi volumio[1216]: info: FusionDsp - ---- read samplerate from file: 44100 Dec 14 08:15:59 hifi volumio[1216]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" 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" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=info msg="loaded track \"Through a Glass\" (paused: false, position: 0ms, duration: 180273ms, prefetched: false)" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi volumio[1216]: info: FusionDsp - {"Reload":{"result":"Ok"}} Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:15:59 hifi volumio[1612]: .......................++++ Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:15:59 hifi volumio[1216]: info: camilladsp spawned new process with pid 1644, instance 1, run: true Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="scheduling prefetch in 150s" Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=trace msg="emitting websocket event: metadata" Dec 14 08:15:59 hifi volumio[1216]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0JoNMwglQorgs5Rz2xYK6b","name":"Through a Glass","artist_names":["Henry Jamison"],"album_name":"The Wilds","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02962378eb5a05ef5951e98058","position":0,"duration":180273,"release_date":"year:2017 month:10 day:27","track_number":4,"disc_number":1}} Dec 14 08:15:59 hifi go-librespot[1508]: time="2025-12-14T08:15:59Z" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:16:00 hifi go-librespot[1508]: time="2025-12-14T08:16:00Z" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:16:00 hifi go-librespot[1508]: time="2025-12-14T08:16:00Z" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:16:00 hifi go-librespot[1508]: time="2025-12-14T08:16:00Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 14 08:16:00 hifi go-librespot[1508]: time="2025-12-14T08:16:00Z" level=trace msg="emitting websocket event: playing" Dec 14 08:16:00 hifi volumio[1216]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:7EAoJP31PjLvpWjjhnqyNA","uri":"spotify:track:0JoNMwglQorgs5Rz2xYK6b","resume":false,"play_origin":"playlist"}} Dec 14 08:16:00 hifi volumio[1216]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 14 08:16:00 hifi volumio[1216]: TypeError: Cannot read property 'service' of undefined Dec 14 08:16:00 hifi volumio[1216]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Dec 14 08:16:00 hifi volumio[1216]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Dec 14 08:16:00 hifi volumio[1216]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Dec 14 08:16:00 hifi volumio[1216]: at WebSocket.emit (events.js:315:20) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.emit (events.js:315:20) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 14 08:16:00 hifi volumio[1216]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 14 08:16:00 hifi volumio[1216]: at writeOrBuffer (internal/streams/writable.js:358:12) Dec 14 08:16:00 hifi volumio[1216]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Dec 14 08:16:00 hifi volumio[1216]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Dec 14 08:16:00 hifi volumio[1216]: at Socket.emit (events.js:315:20) Dec 14 08:16:00 hifi volumio[1216]: at addChunk (internal/streams/readable.js:309:12) Dec 14 08:16:00 hifi volumio[1216]: at readableAddChunk (internal/streams/readable.js:284:9) Dec 14 08:16:00 hifi volumio[1216]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 14 08:16:00 hifi go-librespot[1508]: time="2025-12-14T08:16:00Z" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:0JoNMwglQorgs5Rz2xYK6b" Dec 14 08:16:00 hifi volumio[1612]: .....++++ Dec 14 08:16:00 hifi volumio[1612]: e is 65537 (0x010001) Dec 14 08:16:00 hifi sudo[1660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-14 08:15 Dec 14 08:16:00 hifi sudo[1660]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 14 08:16:00 hifi volumio[1612]: writing RSA key 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"