-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Mon 2025-04-21 11:15:21 CEST. -- Apr 21 11:15:06 p-volumio systemd-timedated[1033]: Changed local time to Mon Apr 21 11:15:06 2025 Apr 21 11:15:06 p-volumio sudo[1031]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:06 p-volumio systemd[1]: Starting Daily apt download activities... Apr 21 11:15:06 p-volumio volumio-time-update[618]: volumio-time-update-util: System time updated successfully. Apr 21 11:15:06 p-volumio systemd[1]: Started Volumio Time Update Utility. Apr 21 11:15:06 p-volumio volumio[1001]: info: MYVOLUMIO Environment detected Apr 21 11:15:06 p-volumio nmbd[748]: [2025/04/21 11:15:06.783570, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 11:15:06 p-volumio systemd[1]: Started Samba NMB Daemon. Apr 21 11:15:06 p-volumio nmbd[748]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Apr 21 11:15:06 p-volumio systemd[1]: Starting Samba Winbind Daemon... Apr 21 11:15:07 p-volumio volumio[1001]: info: Plugin folders cleanup Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning into folder /volumio/app/plugins/ Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category audio_interface Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category miscellanea Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category music_service Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category plugins.json Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category system_controller Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category user_interface Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning into folder /data/plugins/ Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category audio_interface Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category music_service Apr 21 11:15:07 p-volumio volumio[1001]: info: Scanning category system_controller Apr 21 11:15:07 p-volumio volumio[1001]: info: Plugin folders cleanup completed Apr 21 11:15:07 p-volumio volumio[1001]: info: ------------------------------------------- Apr 21 11:15:07 p-volumio volumio[1001]: info: ----- Core plugins startup ---- Apr 21 11:15:07 p-volumio volumio[1001]: info: ------------------------------------------- Apr 21 11:15:07 p-volumio volumio[1001]: info: Loading plugins from folder /volumio/app/plugins/ Apr 21 11:15:07 p-volumio volumio[1001]: info: Adding plugin upnp to MyMusic Plugins Apr 21 11:15:07 p-volumio volumio[1001]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 21 11:15:07 p-volumio volumio[1001]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 21 11:15:07 p-volumio volumio[1001]: info: Loading plugins from folder /data/plugins/ Apr 21 11:15:07 p-volumio volumio[1001]: info: Loading plugin "system"... Apr 21 11:15:07 p-volumio volumio[1001]: info: Loading plugin "appearance"... Apr 21 11:15:07 p-volumio winbindd[1056]: [2025/04/21 11:15:07.106501, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 21 11:15:07 p-volumio winbindd[1056]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 21 11:15:07 p-volumio winbindd[1056]: [2025/04/21 11:15:07.172789, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 11:15:07 p-volumio systemd[1]: Started Samba Winbind Daemon. Apr 21 11:15:07 p-volumio winbindd[1056]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 21 11:15:07 p-volumio systemd[1]: Starting Samba SMB Daemon... Apr 21 11:15:07 p-volumio smbd[1064]: [2025/04/21 11:15:07.702656, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 21 11:15:07 p-volumio smbd[1064]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 21 11:15:07 p-volumio systemd[1]: Started Samba SMB Daemon. Apr 21 11:15:07 p-volumio systemd[1]: Reached target Multi-User System. Apr 21 11:15:07 p-volumio systemd[1]: Reached target Graphical Interface. Apr 21 11:15:07 p-volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 21 11:15:07 p-volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 21 11:15:07 p-volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 21 11:15:07 p-volumio volumio-remote-updater[601]: [2025-04-21 11:15:07] [connect] Successful connection Apr 21 11:15:08 p-volumio systemd[1]: apt-daily.service: Succeeded. Apr 21 11:15:08 p-volumio systemd[1]: Started Daily apt download activities. Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "network"... Apr 21 11:15:08 p-volumio volumio[1001]: info: Refreshing Cached IP Addresses Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "services"... Apr 21 11:15:08 p-volumio systemd[1]: Starting Daily apt upgrade and clean activities... Apr 21 11:15:08 p-volumio sudo[1104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 21 11:15:08 p-volumio sudo[1104]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:08 p-volumio sudo[1106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 21 11:15:08 p-volumio sudo[1104]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:08 p-volumio sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:08 p-volumio sudo[1106]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "alsa_controller"... Apr 21 11:15:08 p-volumio sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 21 11:15:08 p-volumio sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:08 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "wizard"... Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "networkfs"... Apr 21 11:15:08 p-volumio volumio[1001]: info: Starting Udev Watcher for removable devices Apr 21 11:15:08 p-volumio sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Rob,password=Freed0m2!o3!6,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.4/music\\albums (mp3) /mnt/NAS/Albums_(mp3) Apr 21 11:15:08 p-volumio sudo[1147]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:08 p-volumio volumio[1001]: info: Ignoring mount for partition: boot Apr 21 11:15:08 p-volumio volumio[1001]: info: Ignoring mount for partition: volumio Apr 21 11:15:08 p-volumio volumio[1001]: info: Ignoring mount for partition: volumio_data Apr 21 11:15:08 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "volumio_command_line_client"... Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "upnp"... Apr 21 11:15:08 p-volumio volumio[1001]: info: [1745226908617] Starting Upmpd Daemon Apr 21 11:15:08 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "my_music"... Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "mpd"... Apr 21 11:15:08 p-volumio kernel: Key type cifs.spnego registered Apr 21 11:15:08 p-volumio kernel: Key type cifs.idmap registered Apr 21 11:15:08 p-volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Apr 21 11:15:08 p-volumio kernel: CIFS: Attempting to mount //192.168.178.4/music/albums (mp3) Apr 21 11:15:08 p-volumio volumio[1001]: info: Loading plugin "upnp_browser"... Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "alarm-clock"... Apr 21 11:15:09 p-volumio sudo[1147]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "airplay_emulation"... Apr 21 11:15:09 p-volumio volumio[1001]: info: Starting Shairport Sync Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "last_100"... Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "webradio"... Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "i2s_dacs"... Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "volumiodiscovery"... Apr 21 11:15:09 p-volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Apr 21 11:15:09 p-volumio systemd[1]: Started Daily apt upgrade and clean activities. Apr 21 11:15:09 p-volumio systemd[1]: Startup finished in 11.794s (kernel) + 28.160s (userspace) = 39.954s. Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** For more information see Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 11:15:09 p-volumio volumio[1001]: *** WARNING *** For more information see Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** For more information see Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 21 11:15:09 p-volumio node[1001]: *** WARNING *** For more information see Apr 21 11:15:09 p-volumio volumio[1001]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 21 11:15:09 p-volumio volumio[1001]: info: Discovery: Started advertising with name: P-Volumio Apr 21 11:15:09 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 21 11:15:09 p-volumio volumio[1001]: info: Loading plugin "spop"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "outputs"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "albumart"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Plugin example_plugin is not enabled Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "inputs"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "updater_comm"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Plugin mpdemulation is not enabled Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "rest_api"... Apr 21 11:15:10 p-volumio volumio[1001]: info: Loading plugin "websocket"... Apr 21 11:15:11 p-volumio volumio[1001]: info: Starting Socket.io Server version 2.3.0 Apr 21 11:15:11 p-volumio volumio[1001]: info: Loading plugin "fusiondsp"... Apr 21 11:15:11 p-volumio volumio[1001]: Forking 3 albumart workers Apr 21 11:15:11 p-volumio volumio[1001]: info: Applying required configuration parameters for plugin fusiondsp Apr 21 11:15:11 p-volumio volumio[1001]: info: Loading plugin "backup_restore"... Apr 21 11:15:11 p-volumio volumio[1001]: Starting albumart workers Apr 21 11:15:11 p-volumio volumio[1001]: Starting albumart workers Apr 21 11:15:11 p-volumio volumio[1001]: Starting albumart workers Apr 21 11:15:11 p-volumio volumio[1001]: info: Applying required configuration parameters for plugin backup_restore Apr 21 11:15:11 p-volumio volumio[1001]: info: Loading i18n strings for locale en Apr 21 11:15:11 p-volumio volumio[1001]: Updating browse sources language Apr 21 11:15:11 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 11:15:12 p-volumio sudo[1117]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::initPlayerControls Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: Express server listening on port 3000 Apr 21 11:15:12 p-volumio volumio[1001]: [Metrics] WebUI: 6s 984.27ms Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::resetVolumioState Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::getcurrentVolume Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioRetrievevolume Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::pushState Apr 21 11:15:12 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioPushState Apr 21 11:15:12 p-volumio volumio[1001]: info: Volumio Network Manager: Network status updated: 2 Apr 21 11:15:12 p-volumio volumio-remote-updater[601]: [2025-04-21 11:15:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1745226907 101 Apr 21 11:15:12 p-volumio volumio[1001]: 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 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: Reloading queue from file Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::setRepeat null single undefined Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::pushState Apr 21 11:15:12 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioPushState Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::setRandom null Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreStateMachine::pushState Apr 21 11:15:12 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioPushState Apr 21 11:15:12 p-volumio volumio[1001]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 21 11:15:12 p-volumio volumio[1001]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Apr 21 11:15:12 p-volumio volumio[1001]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 21 11:15:12 p-volumio volumio[1001]: info: Setting Device type: Raspberry PI Apr 21 11:15:12 p-volumio volumio[1001]: info: Completed loading Core Plugins Apr 21 11:15:12 p-volumio volumio[1001]: info: Preparing to generate the ALSA configuration file Apr 21 11:15:12 p-volumio volumio[1001]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 21 11:15:12 p-volumio volumio[1001]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 21 11:15:12 p-volumio volumio[1001]: info: Reading ALSA contributions from plugins. Apr 21 11:15:12 p-volumio volumio[1001]: info: Asound.conf file unchanged, so no further update is needed Apr 21 11:15:12 p-volumio volumio[1001]: info: Output device has changed, restarting MPD Apr 21 11:15:12 p-volumio sudo[1269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 21 11:15:12 p-volumio volumio[1001]: info: Output device has changed, restarting Shairport Sync Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio sudo[1269]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:12 p-volumio sudo[1271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 21 11:15:12 p-volumio sudo[1271]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio systemd[1]: Stopping Music Player Daemon... Apr 21 11:15:12 p-volumio volumio[1001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 11:15:12 p-volumio volumio[1001]: info: ___________ START PLUGINS ___________ Apr 21 11:15:12 p-volumio volumio[1001]: info: ControllerMpd::onStart: Initializing MPD Apr 21 11:15:12 p-volumio volumio[1001]: info: Creating MPD Configuration file Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 11:15:12 p-volumio volumio[1001]: info: [1745226912436] CoreMusicLibrary::Adding element Media Servers Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 11:15:12 p-volumio sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 21 11:15:12 p-volumio sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio sudo[1278]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:12 p-volumio sudo[1280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 21 11:15:12 p-volumio sudo[1280]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio systemd[1]: mpd.service: Succeeded. Apr 21 11:15:12 p-volumio systemd[1]: Stopped Music Player Daemon. Apr 21 11:15:12 p-volumio volumio[1001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 11:15:12 p-volumio volumio[1001]: info: [1745226912530] CoreMusicLibrary::Adding element Last_100 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 11:15:12 p-volumio systemd[1]: Starting Music Player Daemon... Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 21 11:15:12 p-volumio volumio[1001]: info: [1745226912533] CoreMusicLibrary::Adding element Webradio Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 21 11:15:12 p-volumio volumio[1001]: info: Initializing BBC Radios Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio sudo[1286]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 21 11:15:12 p-volumio sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio sudo[1286]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:12 p-volumio volumio[1001]: info: Creating Spotify config file Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: Loading i18n strings for locale en Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: FusionDsp - mixtype--------------------- None Apr 21 11:15:12 p-volumio volumio[1001]: info: Volumio Calling Home Apr 21 11:15:12 p-volumio volumio[1001]: info: Preparing to generate the ALSA configuration file Apr 21 11:15:12 p-volumio volumio[1001]: info: Discovery: adding c9c2d98b-5ac0-4781-aabf-2721a196142a Apr 21 11:15:12 p-volumio volumio[1001]: info: Discovery: Found device P-Volumio Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::volumioGetState Apr 21 11:15:12 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:12 p-volumio volumio[1001]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 21 11:15:12 p-volumio volumio[1001]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 21 11:15:12 p-volumio volumio[1001]: info: Reading ALSA contributions from plugins. Apr 21 11:15:12 p-volumio volumio[1001]: info: MPD Permissions set Apr 21 11:15:12 p-volumio volumio[1001]: info: MPD Permissions set Apr 21 11:15:12 p-volumio volumio[1001]: info: Spotify config file written Apr 21 11:15:12 p-volumio sudo[1306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 21 11:15:12 p-volumio sudo[1306]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:12 p-volumio volumio[1001]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:12 p-volumio volumio[1001]: info: No need to fix Spotify hosts Apr 21 11:15:12 p-volumio systemd[1]: Started go-librespot Daemon. Apr 21 11:15:12 p-volumio go-librespot[1312]: Librespot-go daemon starting... Apr 21 11:15:12 p-volumio sudo[1306]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:12 p-volumio volumio[1001]: info: Volumio called home Apr 21 11:15:12 p-volumio volumio[1001]: info: Starting Shairport Sync Apr 21 11:15:12 p-volumio volumio[1001]: info: Starting Shairport Sync Apr 21 11:15:12 p-volumio volumio[1001]: info: Starting Shairport Sync Apr 21 11:15:12 p-volumio sudo[1319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 11:15:12 p-volumio sudo[1319]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio sudo[1321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 11:15:13 p-volumio sudo[1321]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::volumioGetState Apr 21 11:15:13 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:13 p-volumio systemd[1]: shairport-sync.service: Succeeded. Apr 21 11:15:13 p-volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio sudo[1325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 11:15:13 p-volumio sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio volumio[1001]: info: Asound.conf file unchanged, so no further update is needed Apr 21 11:15:13 p-volumio volumio[1001]: info: Output device has changed, restarting MPD Apr 21 11:15:13 p-volumio volumio[1001]: info: Output device has changed, restarting Shairport Sync Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:13 p-volumio sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 21 11:15:13 p-volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio sudo[1334]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio sudo[1336]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 21 11:15:13 p-volumio sudo[1336]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio sudo[1319]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 11:15:13 p-volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 21 11:15:13 p-volumio systemd[1]: shairport-sync.service: Succeeded. Apr 21 11:15:13 p-volumio sudo[1321]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio volumio[1001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 21 11:15:13 p-volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio sudo[1325]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 21 11:15:13 p-volumio systemd[1]: mpd.service: Succeeded. Apr 21 11:15:13 p-volumio systemd[1]: Stopped Music Player Daemon. Apr 21 11:15:13 p-volumio systemd[1]: Starting Music Player Daemon... Apr 21 11:15:13 p-volumio volumio[1001]: info: MPD Permissions set Apr 21 11:15:13 p-volumio volumio[1001]: info: Shairport-Sync Started Apr 21 11:15:13 p-volumio volumio[1001]: Error adding Membership: Error: addMembership EINVAL Apr 21 11:15:13 p-volumio volumio[1001]: info: Shairport-Sync Started Apr 21 11:15:13 p-volumio volumio[1001]: info: Shairport-Sync Started Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio go-librespot[1312]: time="2025-04-21T11:15:13+02:00" level=info msg="generated new device id: 246fa356ef7a6a8fa5760f891c72b830e1fdcc71" Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:13 p-volumio volumio[1001]: info: Starting Shairport Sync Apr 21 11:15:13 p-volumio sudo[1351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 21 11:15:13 p-volumio sudo[1351]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio sudo[1343]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 21 11:15:13 p-volumio sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:13 p-volumio sudo[1343]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 21 11:15:13 p-volumio systemd[1]: shairport-sync.service: Succeeded. Apr 21 11:15:13 p-volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 21 11:15:13 p-volumio sudo[1351]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:13 p-volumio volumio[1001]: info: Shairport-Sync Started Apr 21 11:15:13 p-volumio go-librespot[1312]: time="2025-04-21T11:15:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 21 11:15:13 p-volumio go-librespot[1312]: time="2025-04-21T11:15:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 21 11:15:13 p-volumio go-librespot[1312]: time="2025-04-21T11:15:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 21 11:15:13 p-volumio go-librespot[1312]: time="2025-04-21T11:15:13+02:00" level=debug msg="zeroconf server listening on port 45391" Apr 21 11:15:13 p-volumio mpd[1354]: Apr 21 11:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 21 11:15:14 p-volumio systemd[1]: Started Music Player Daemon. Apr 21 11:15:14 p-volumio sudo[1336]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:14 p-volumio sudo[1271]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:14 p-volumio sudo[1280]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:14 p-volumio volumio[1001]: info: Completed starting Core Plugins Apr 21 11:15:14 p-volumio volumio[1001]: info: ------------------------------------------- Apr 21 11:15:14 p-volumio volumio[1001]: info: ----- MyVolumio plugins startup ---- Apr 21 11:15:14 p-volumio volumio[1001]: info: ------------------------------------------- Apr 21 11:15:14 p-volumio volumio[1001]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 21 11:15:14 p-volumio volumio[1001]: error: MPD error: The expression evaluated to a falsy value: Apr 21 11:15:14 p-volumio volumio[1001]: assert.ok(self.idling) Apr 21 11:15:14 p-volumio volumio[1001]: error: The expression evaluated to a falsy value: Apr 21 11:15:14 p-volumio volumio[1001]: assert.ok(self.idling) Apr 21 11:15:14 p-volumio volumio[1001]: error: MPD error: The expression evaluated to a falsy value: Apr 21 11:15:14 p-volumio volumio[1001]: assert.ok(self.idling) Apr 21 11:15:14 p-volumio volumio[1001]: error: The expression evaluated to a falsy value: Apr 21 11:15:14 p-volumio volumio[1001]: assert.ok(self.idling) Apr 21 11:15:14 p-volumio volumio[1001]: info: MPD running with PID1354 Apr 21 11:15:14 p-volumio volumio[1001]: ,establishing connection Apr 21 11:15:14 p-volumio volumio[1001]: error: updateQueue error: null Apr 21 11:15:14 p-volumio volumio[1001]: error: updateQueue error: null Apr 21 11:15:14 p-volumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 21 11:15:14 p-volumio volumio[1001]: info: camilladsp spawned new process with pid 1370, instance 1, run: true Apr 21 11:15:14 p-volumio volumio[1001]: info: camilladsp service started and running in background, instance 1 Apr 21 11:15:14 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 21 11:15:14 p-volumio volumio[1001]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Apr 21 11:15:14 p-volumio volumio[1001]: info: FusionDsp loaded Apr 21 11:15:14 p-volumio volumio[1001]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 21 11:15:14 p-volumio sudo[1374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 21 11:15:14 p-volumio sudo[1374]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:14 p-volumio volumio[1001]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 21 11:15:14 p-volumio volumio[1001]: info: Adding Signal Path Element [object Object] Apr 21 11:15:14 p-volumio volumio[1001]: info: Adding fusiondspeq DSP Signal Path Element Apr 21 11:15:14 p-volumio volumio[1001]: info: FusionDsp - ---- installed callbackRead Apr 21 11:15:14 p-volumio volumio[1001]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 21 11:15:14 p-volumio volumio[1001]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 21 11:15:14 p-volumio volumio[1001]: error: FusionDsp - WebSocket error: [object Object] Apr 21 11:15:14 p-volumio systemd[1]: Started FusionDsp Daemon. Apr 21 11:15:14 p-volumio sudo[1374]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:14 p-volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Apr 21 11:15:14 p-volumio sh[528]: timed out Apr 21 11:15:14 p-volumio dhcpcd[577]: timed out Apr 21 11:15:14 p-volumio sh[528]: dhcpcd exited Apr 21 11:15:14 p-volumio dhcpcd[577]: dhcpcd exited Apr 21 11:15:14 p-volumio sh[528]: ifup: failed to bring up eth0 Apr 21 11:15:14 p-volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Apr 21 11:15:14 p-volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Apr 21 11:15:15 p-volumio volumio[1001]: info: go-librespot daemon successfully initialized Apr 21 11:15:16 p-volumio systemd[1]: systemd-hostnamed.service: Succeeded. Apr 21 11:15:18 p-volumio sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 21 11:15:18 p-volumio sudo[1402]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:18 p-volumio sudo[1402]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:18 p-volumio sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 21 11:15:18 p-volumio sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:18 p-volumio sudo[1404]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:18 p-volumio sudo[1408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 21 11:15:18 p-volumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 21 11:15:18 p-volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 21 11:15:18 p-volumio sudo[1408]: pam_unix(sudo:session): session closed for user root Apr 21 11:15:18 p-volumio volumio[1001]: info: Upmpdcli Daemon Started Apr 21 11:15:18 p-volumio volumio[1410]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 21 11:15:18 p-volumio volumio[1001]: info: Initializing connection to go-librespot Websocket Apr 21 11:15:18 p-volumio go-librespot[1312]: time="2025-04-21T11:15:18+02:00" level=debug msg="new websocket client" Apr 21 11:15:18 p-volumio volumio[1001]: info: Connection to go-librespot Websocket established Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="obtained new client token: AABGIKd90lpr9V0uYE9gR5gxIoAjzP8waXF3J2tKNZGkNjWPR1pgLwNLCShjnF9upCVCiLSBBq+cHoEDEJ1S4Si7I6J3NLU2EJyG3aaOu7/k/xkKMNHj0cAdMbFxpxsLrnyLj9xdY6mAj6LOoQQLHAbw9M9OZI5OgOWGuO5gNE7J2LHniNfsBVFf09dpJ/mYtMCaZKZnbpRhemzwha5IqBX/q5/Tdom6S5JoJXRuhrcbufKZHCcjBmm5UIJT" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="completed keyexchange" Apr 21 11:15:19 p-volumio volumio[1001]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="completed challenge" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="authenticated as ra59.boeije" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="authenticated as ra59.boeije" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="dealer connection opened" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=info msg="accepted zeroconf user ra59.boeije from S10e van Rob" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="autoplay enabled: false" Apr 21 11:15:19 p-volumio go-librespot[1312]: time="2025-04-21T11:15:19+02:00" level=debug msg="received connection id: MzI3YWNlZjgtNWE3OS00NjlmLWFjYjMtODU3MGRkMmUxMjBlK2RlYWxlcit0Y3A6Ly8wYWNhNThhNi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQTc3RDE1REI0ODlBNEMwMDYzNzYxRjY1NkE4NUJGMThGQkY2RjkzQTUzRTM2NUJFOTdGNDZCMEMxQ0U5NDdGNA==" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="handling transfer player command from 367ea25a6db630548e289c8ba41ee3215b13139d" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:3fQzkax0cUhSYp6H5vFpeC" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=trace msg="fetched new page 0 with 65 items (list: 65)" uri="spotify:playlist:3fQzkax0cUhSYp6H5vFpeC" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="loading track (paused: true, position: 212661ms)" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=trace msg="emitting websocket event: will_play" Apr 21 11:15:20 p-volumio volumio[1001]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4d6eqRtpDX7tydHJGDZUBQ","play_origin":"playlist"}} Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="selected format OGG_VORBIS_320 (ffce806872398df3d7487ce26ff645da188845f7)" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="requested aes key for file ffce806872398df3d7487ce26ff645da188845f7, gid: 4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1674" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="fetched first chunk of 20, total size is 10004388 bytes" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:20 p-volumio go-librespot[1312]: time="2025-04-21T11:15:20+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="fetched chunk 19/19, size: 42916" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="fetched chunk 18/19, size: 524288" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=trace msg="seek to 212661ms (diff: 142ms, samples: 9378350, bytes: 9885425)" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1282" Apr 21 11:15:21 p-volumio volumio[1001]: info: FusionDsp - ---- read samplerate, raw: Apr 21 11:15:21 p-volumio volumio[1001]: error: FusionDsp - invalid sample rate Apr 21 11:15:21 p-volumio volumio[1001]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="created new output device" Apr 21 11:15:21 p-volumio volumio[1001]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 21 11:15:21 p-volumio volumio[1001]: info: camilladsp stopping service pid 1370... Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=info msg="loaded track \"She Drives Me Crazy\" (paused: true, position: 212661ms, duration: 215773ms, prefetched: false)" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio volumio[1001]: info: camilladsp service terminated, instance 1 Apr 21 11:15:21 p-volumio volumio[1001]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 21 11:15:21 p-volumio volumio[1001]: info: camilladsp service started and running in background, instance 1 Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:4d6eqRtpDX7tydHJGDZUBQ" Apr 21 11:15:21 p-volumio volumio[1001]: info: camilladsp spawned new process with pid 1430, instance 1, run: true Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=trace msg="emitting websocket event: metadata" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=trace msg="emitting websocket event: active" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="sending successful reply for dealer request" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 21 11:15:21 p-volumio volumio[1001]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4d6eqRtpDX7tydHJGDZUBQ","name":"She Drives Me Crazy","artist_names":["Fine Young Cannibals"],"album_name":"The Raw \u0026 The Cooked","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c573a4a852f010523c4ba383","position":212661,"duration":215773,"release_date":"year:1988 month:1 day:1","track_number":1,"disc_number":1}} Apr 21 11:15:21 p-volumio volumio[1001]: SPOTIFY: received: {"type":"active","data":null} Apr 21 11:15:21 p-volumio volumio[1001]: info: Aligning Spotify Volume to Volumio Volume Apr 21 11:15:21 p-volumio volumio[1001]: info: CoreCommandRouter::volumioGetState Apr 21 11:15:21 p-volumio volumio[1001]: info: CorePlayQueue::getTrack 0 Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 21 11:15:21 p-volumio go-librespot[1312]: time="2025-04-21T11:15:21+02:00" level=trace msg="emitting websocket event: paused" Apr 21 11:15:21 p-volumio volumio[1001]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4d6eqRtpDX7tydHJGDZUBQ","play_origin":"playlist"}} Apr 21 11:15:21 p-volumio volumio[1001]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 21 11:15:21 p-volumio volumio[1001]: TypeError: Cannot read property 'service' of undefined Apr 21 11:15:21 p-volumio volumio[1001]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Apr 21 11:15:21 p-volumio volumio[1001]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) Apr 21 11:15:21 p-volumio volumio[1001]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Apr 21 11:15:21 p-volumio volumio[1001]: at WebSocket.emit (events.js:315:20) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.emit (events.js:315:20) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 21 11:15:21 p-volumio volumio[1001]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 21 11:15:21 p-volumio volumio[1001]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 21 11:15:21 p-volumio volumio[1001]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 21 11:15:21 p-volumio volumio[1001]: at Socket.emit (events.js:315:20) Apr 21 11:15:21 p-volumio volumio[1001]: at addChunk (internal/streams/readable.js:309:12) Apr 21 11:15:21 p-volumio volumio[1001]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 21 11:15:21 p-volumio volumio[1001]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 21 11:15:21 p-volumio sudo[1446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-21 11:14 Apr 21 11:15:21 p-volumio 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"