-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-09-07 12:44:35 CEST. -- Sep 07 12:43:56 volumio systemd-timedated[908]: Changed local time to Sun Sep 7 12:43:56 2025 Sep 07 12:43:56 volumio ifplugd(eth0)[810]: Program executed successfully. Sep 07 12:43:56 volumio sudo[867]: pam_unix(sudo:session): session closed for user root Sep 07 12:43:56 volumio ifplugd[782]: Network Interface Plugging Daemon...start eth0...done. Sep 07 12:43:56 volumio systemd[1]: Started LSB: Brings up/down network automatically. Sep 07 12:43:56 volumio volumio-time-update[568]: volumio-time-update-util: System time updated successfully. Sep 07 12:43:56 volumio systemd[1]: Started Volumio Time Update Utility. Sep 07 12:43:56 volumio ntpd[811]: Soliciting pool server 5.42.158.119 Sep 07 12:43:57 volumio ntpd[811]: Soliciting pool server 5.39.80.51 Sep 07 12:43:57 volumio nmbd[791]: [2025/09/07 12:43:57.124078, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 07 12:43:57 volumio nmbd[791]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Sep 07 12:43:57 volumio systemd[1]: Started Samba NMB Daemon. Sep 07 12:43:57 volumio systemd[1]: Starting Samba Winbind Daemon... Sep 07 12:43:57 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:43:57 volumio volumio[844]: info: ----- Volumio3 ---- Sep 07 12:43:57 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:43:57 volumio volumio[844]: info: ----- System startup ---- Sep 07 12:43:57 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:43:57 volumio winbindd[932]: [2025/09/07 12:43:57.552270, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Sep 07 12:43:57 volumio winbindd[932]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Sep 07 12:43:57 volumio winbindd[932]: [2025/09/07 12:43:57.573917, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 07 12:43:57 volumio winbindd[932]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Sep 07 12:43:57 volumio systemd[1]: Started Samba Winbind Daemon. Sep 07 12:43:57 volumio systemd[1]: Starting Samba SMB Daemon... Sep 07 12:43:58 volumio ntpd[811]: Soliciting pool server 82.66.40.79 Sep 07 12:43:58 volumio winbindd[932]: [2025/09/07 12:43:58.191970, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Sep 07 12:43:58 volumio winbindd[932]: res_names->count = 3, expected 4 Sep 07 12:43:58 volumio smbd[937]: [2025/09/07 12:43:58.224997, 0] ../lib/util/become_daemon.c:138(daemon_ready) Sep 07 12:43:58 volumio systemd[1]: Started Samba SMB Daemon. Sep 07 12:43:58 volumio smbd[937]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Sep 07 12:43:58 volumio systemd[1]: Reached target Multi-User System. Sep 07 12:43:58 volumio systemd[1]: Reached target Graphical Interface. Sep 07 12:43:58 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Sep 07 12:43:58 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Sep 07 12:43:58 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Sep 07 12:43:58 volumio systemd[1]: Startup finished in 13.646s (kernel) + 14.274s (userspace) = 27.921s. Sep 07 12:43:58 volumio volumio[844]: info: MYVOLUMIO Environment detected Sep 07 12:43:58 volumio volumio[844]: info: Plugin folders cleanup Sep 07 12:43:58 volumio volumio[844]: info: Scanning into folder /volumio/app/plugins/ Sep 07 12:43:59 volumio volumio[844]: info: Scanning category audio_interface Sep 07 12:43:59 volumio volumio[844]: info: Scanning category miscellanea Sep 07 12:43:59 volumio volumio[844]: info: Scanning category music_service Sep 07 12:43:59 volumio volumio[844]: info: Scanning category plugins.json Sep 07 12:43:59 volumio volumio[844]: info: Scanning category system_controller Sep 07 12:43:59 volumio volumio[844]: info: Scanning category user_interface Sep 07 12:43:59 volumio volumio[844]: info: Scanning into folder /data/plugins/ Sep 07 12:43:59 volumio volumio[844]: info: Scanning category audio_interface Sep 07 12:43:59 volumio volumio[844]: info: Scanning category music_service Sep 07 12:43:59 volumio volumio[844]: info: Scanning category system_controller Sep 07 12:43:59 volumio volumio[844]: info: Scanning category user_interface Sep 07 12:43:59 volumio volumio[844]: info: Plugin folders cleanup completed Sep 07 12:43:59 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:43:59 volumio volumio[844]: info: ----- Core plugins startup ---- Sep 07 12:43:59 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:43:59 volumio volumio[844]: info: Loading plugins from folder /volumio/app/plugins/ Sep 07 12:43:59 volumio volumio[844]: info: Adding plugin upnp to MyMusic Plugins Sep 07 12:43:59 volumio volumio[844]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 07 12:43:59 volumio volumio[844]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 07 12:43:59 volumio ntpd[811]: Soliciting pool server 176.137.36.37 Sep 07 12:43:59 volumio volumio[844]: info: Loading plugins from folder /data/plugins/ Sep 07 12:43:59 volumio volumio[844]: info: Loading plugin "system"... Sep 07 12:43:59 volumio volumio[844]: info: Loading plugin "appearance"... Sep 07 12:44:00 volumio ntpd[811]: Soliciting pool server 51.68.44.27 Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "network"... Sep 07 12:44:00 volumio volumio[844]: info: Refreshing Cached IP Addresses Sep 07 12:44:00 volumio sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 07 12:44:00 volumio sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "services"... Sep 07 12:44:00 volumio sudo[952]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:00 volumio sudo[954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "alsa_controller"... Sep 07 12:44:00 volumio sudo[954]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:00 volumio sudo[954]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:00 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "wizard"... Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "networkfs"... Sep 07 12:44:00 volumio volumio[844]: info: Starting Udev Watcher for removable devices Sep 07 12:44:00 volumio sudo[975]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=jeffdeleffe,password=W1x2c3A1z2e3SYN&$%,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.2.8/music /mnt/NAS/Nas Sep 07 12:44:00 volumio sudo[975]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:00 volumio volumio[844]: info: Ignoring mount for partition: boot Sep 07 12:44:00 volumio volumio[844]: info: Ignoring mount for partition: volumio Sep 07 12:44:00 volumio volumio[844]: info: Ignoring mount for partition: volumio_data Sep 07 12:44:00 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "volumio_command_line_client"... Sep 07 12:44:00 volumio volumio[844]: info: Loading plugin "upnp"... Sep 07 12:44:01 volumio ntpd[811]: Soliciting pool server 45.13.105.44 Sep 07 12:44:01 volumio volumio[844]: info: [1757241841018] Starting Upmpd Daemon Sep 07 12:44:01 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 07 12:44:01 volumio volumio[844]: info: Loading plugin "my_music"... Sep 07 12:44:01 volumio volumio[844]: info: Loading plugin "mpd"... Sep 07 12:44:01 volumio kernel: Key type cifs.spnego registered Sep 07 12:44:01 volumio kernel: Key type cifs.idmap registered Sep 07 12:44:01 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Sep 07 12:44:01 volumio kernel: CIFS: Attempting to mount //192.168.2.8/music Sep 07 12:44:01 volumio kernel: cryptd: max_cpu_qlen set to 1000 Sep 07 12:44:01 volumio volumio[844]: info: Loading plugin "upnp_browser"... Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "alarm-clock"... Sep 07 12:44:02 volumio volumio-remote-updater[579]: [2025-09-07 12:44:02] [connect] Successful connection Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "airplay_emulation"... Sep 07 12:44:02 volumio volumio[844]: info: Starting Shairport Sync Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "last_100"... Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "webradio"... Sep 07 12:44:02 volumio sudo[975]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "i2s_dacs"... Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "volumiodiscovery"... Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** For more information see Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 07 12:44:02 volumio node[844]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 07 12:44:02 volumio volumio[844]: *** WARNING *** For more information see Sep 07 12:44:02 volumio node[844]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 07 12:44:02 volumio node[844]: *** WARNING *** For more information see Sep 07 12:44:02 volumio node[844]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 07 12:44:02 volumio node[844]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 07 12:44:02 volumio node[844]: *** WARNING *** For more information see Sep 07 12:44:02 volumio volumio[844]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 07 12:44:02 volumio volumio[844]: info: Discovery: Started advertising with name: Volumio Sep 07 12:44:02 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 07 12:44:02 volumio volumio[844]: info: Loading plugin "spop"... Sep 07 12:44:05 volumio volumio[844]: info: Loading plugin "youtube2"... Sep 07 12:44:12 volumio volumio[844]: info: Loading plugin "ytcr"... Sep 07 12:44:18 volumio volumio[844]: info: Loading plugin "ytmusic"... Sep 07 12:44:18 volumio systemd[1]: systemd-fsckd.service: Succeeded. Sep 07 12:44:18 volumio volumio-remote-updater[579]: [2025-09-07 12:44:18] [connect] Successful connection Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "autostart"... Sep 07 12:44:22 volumio volumio[844]: info: Applying required configuration parameters for plugin autostart Sep 07 12:44:22 volumio volumio[844]: info: AutoStart - onVolumioStart - read config.json Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "outputs"... Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "albumart"... Sep 07 12:44:22 volumio volumio[844]: info: Plugin example_plugin is not enabled Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "inputs"... Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "updater_comm"... Sep 07 12:44:22 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Sep 07 12:44:22 volumio volumio[844]: info: Plugin mpdemulation is not enabled Sep 07 12:44:22 volumio volumio[844]: info: Loading plugin "rest_api"... Sep 07 12:44:23 volumio volumio[844]: info: Loading plugin "websocket"... Sep 07 12:44:23 volumio volumio[844]: info: Starting Socket.io Server version 2.3.0 Sep 07 12:44:23 volumio volumio[844]: info: Loading plugin "fusiondsp"... Sep 07 12:44:23 volumio volumio[844]: Forking 3 albumart workers Sep 07 12:44:23 volumio volumio[844]: info: Applying required configuration parameters for plugin fusiondsp Sep 07 12:44:23 volumio volumio[844]: info: Loading plugin "RoonBridge"... Sep 07 12:44:24 volumio volumio[844]: Starting albumart workers Sep 07 12:44:24 volumio volumio[844]: Starting albumart workers Sep 07 12:44:24 volumio volumio[844]: Starting albumart workers Sep 07 12:44:24 volumio volumio[844]: info: Applying required configuration parameters for plugin RoonBridge Sep 07 12:44:24 volumio volumio[844]: info: Plugin touch_display is not enabled Sep 07 12:44:24 volumio volumio[844]: info: Loading i18n strings for locale fr Sep 07 12:44:24 volumio volumio[844]: Updating browse sources language Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::initPlayerControls Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 07 12:44:24 volumio volumio[844]: Express server listening on port 3000 Sep 07 12:44:24 volumio volumio[844]: [Metrics] WebUI: 27s 130.51ms Sep 07 12:44:24 volumio volumio[844]: info: CoreStateMachine::resetVolumioState Sep 07 12:44:24 volumio volumio[844]: info: CoreStateMachine::getcurrentVolume Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::volumioRetrievevolume Sep 07 12:44:24 volumio volumio[844]: info: CoreStateMachine::pushState Sep 07 12:44:24 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 12:44:24 volumio volumio[844]: info: CoreCommandRouter::volumioPushState Sep 07 12:44:24 volumio sudo[1099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 07 12:44:24 volumio sudo[1099]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:24 volumio sudo[1099]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:24 volumio sudo[1107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 07 12:44:24 volumio sudo[1107]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:24 volumio sudo[1107]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:24 volumio volumio[844]: info: Volumio Network Manager: Network status updated: 1 Sep 07 12:44:25 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141:3000 from 192.168.2.106 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 1 Sep 07 12:44:25 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141 from 192.168.2.106 UA: Mozilla/5.0 (Linux; Android 15; 2311DRK48G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.51 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Sep 07 12:44:25 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141 from 192.168.2.106 UA: Mozilla/5.0 (Linux; Android 15; 2311DRK48G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.51 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Sep 07 12:44:25 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141 from 192.168.2.106 UA: Mozilla/5.0 (Linux; Android 15; 2311DRK48G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.51 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Sep 07 12:44:25 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141 from 192.168.2.106 UA: Mozilla/5.0 (Linux; Android 15; 2311DRK48G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/140.0.7339.51 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 07 12:44:25 volumio volumio[844]: info: Creating Thumbnail for file IMG.jpg : /data/backgrounds/thumbnail-IMG.jpg Sep 07 12:44:25 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:25 volumio volumio[844]: info: Reloading queue from file Sep 07 12:44:25 volumio volumio[844]: info: Setting Device type: Raspberry PI Sep 07 12:44:25 volumio volumio[844]: info: CoreStateMachine::setRepeat false single undefined Sep 07 12:44:25 volumio volumio[844]: info: CoreStateMachine::pushState Sep 07 12:44:25 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:25 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 12:44:25 volumio volumio[844]: info: CoreCommandRouter::volumioPushState Sep 07 12:44:25 volumio volumio[844]: info: CoreStateMachine::setRandom false Sep 07 12:44:25 volumio volumio[844]: info: CoreStateMachine::pushState Sep 07 12:44:25 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:25 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 07 12:44:25 volumio volumio[844]: info: CoreCommandRouter::volumioPushState Sep 07 12:44:25 volumio sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 07 12:44:25 volumio sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:25 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Sep 07 12:44:25 volumio sudo[1118]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:26 volumio volumio[844]: Failed to create thumbnail :Error: marker was not found Sep 07 12:44:26 volumio volumio[844]: info: Completed loading Core Plugins Sep 07 12:44:26 volumio volumio[844]: info: Preparing to generate the ALSA configuration file Sep 07 12:44:26 volumio volumio[844]: info: Discovery: adding 41af03d2-12ba-411e-820e-52d5d77f9f15 Sep 07 12:44:26 volumio volumio[844]: info: Discovery: Found device Volumio Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:26 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:26 volumio volumio[844]: info: Upmpdcli Daemon Started Sep 07 12:44:26 volumio volumio[844]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Sep 07 12:44:26 volumio volumio[844]: info: Reading ALSA contributions from plugins. Sep 07 12:44:26 volumio volumio[844]: info: Asound.conf file unchanged, so no further update is needed Sep 07 12:44:26 volumio volumio[844]: info: Output device has changed, restarting MPD Sep 07 12:44:26 volumio sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 07 12:44:26 volumio sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:26 volumio volumio[844]: info: Output device has changed, restarting Shairport Sync Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:26 volumio sudo[1135]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:26 volumio sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 07 12:44:26 volumio sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:26 volumio volumio[1120]: Generating RSA private key, 4096 bit long modulus (2 primes) Sep 07 12:44:26 volumio systemd[1]: Stopping Music Player Daemon... Sep 07 12:44:26 volumio volumio[844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 07 12:44:26 volumio volumio[844]: info: ___________ START PLUGINS ___________ Sep 07 12:44:26 volumio volumio[844]: info: ControllerMpd::onStart: Initializing MPD Sep 07 12:44:26 volumio volumio[844]: info: Creating MPD Configuration file Sep 07 12:44:26 volumio sudo[1144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 07 12:44:26 volumio sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:26 volumio volumio[844]: info: [1757241866969] CoreMusicLibrary::Adding element Serveurs Média Sep 07 12:44:26 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:26 volumio sudo[1144]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:26 volumio sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 07 12:44:26 volumio sudo[1147]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:27 volumio systemd[1]: mpd.service: Succeeded. Sep 07 12:44:27 volumio systemd[1]: Stopped Music Player Daemon. Sep 07 12:44:27 volumio volumio[844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:27 volumio volumio[844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:27 volumio volumio[844]: info: [1757241867155] CoreMusicLibrary::Adding element Last_100 Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:27 volumio volumio[844]: info: [1757241867159] CoreMusicLibrary::Adding element Webradio Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 07 12:44:27 volumio systemd[1]: Starting Music Player Daemon... Sep 07 12:44:27 volumio volumio[844]: info: Initializing BBC Radios Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:27 volumio sudo[1152]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 07 12:44:27 volumio sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:27 volumio sudo[1152]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:27 volumio volumio[844]: info: Creating Spotify config file Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:27 volumio systemd[1]: systemd-timedated.service: Succeeded. Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:27 volumio volumio[844]: info: [1757241867451] CoreMusicLibrary::Adding element YouTube2 Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:27 volumio volumio[844]: Cannot find translation for source YouTube2 Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:27 volumio volumio[844]: info: [1757241867522] CoreMusicLibrary::Adding element YouTube Music Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:27 volumio volumio[844]: Cannot find translation for source YouTube2 Sep 07 12:44:27 volumio volumio[844]: Cannot find translation for source YouTube Music Sep 07 12:44:27 volumio volumio[844]: info: AutoStart - onStart Sep 07 12:44:27 volumio volumio[844]: info: Loading i18n strings for locale fr Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Sep 07 12:44:27 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:27 volumio volumio[844]: info: FusionDsp - mixtype--------------------- None Sep 07 12:44:27 volumio volumio[844]: info: Volumio Calling Home Sep 07 12:44:27 volumio sudo[1172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Sep 07 12:44:27 volumio sudo[1172]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:27 volumio sudo[1172]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:27 volumio volumio[844]: info: Preparing to generate the ALSA configuration file Sep 07 12:44:27 volumio volumio[844]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Sep 07 12:44:27 volumio volumio[844]: info: Reading ALSA contributions from plugins. Sep 07 12:44:27 volumio volumio[844]: error: Cannot start Roon Bridge Error: Command failed: /usr/bin/sudo /bin/systemctl start roonbridge.service Sep 07 12:44:27 volumio volumio[844]: Failed to start roonbridge.service: Unit roonbridge.service not found. Sep 07 12:44:27 volumio volumio[844]: info: MPD Permissions set Sep 07 12:44:27 volumio volumio[844]: info: Spotify config file written Sep 07 12:44:27 volumio sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 07 12:44:27 volumio sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio systemd[1]: Started go-librespot Daemon. Sep 07 12:44:28 volumio go-librespot[1180]: go-librespot daemon starting... Sep 07 12:44:28 volumio sudo[1178]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:28 volumio volumio[844]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Sep 07 12:44:28 volumio volumio[844]: info: Volumio called home Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: No need to fix Spotify hosts Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 12:44:28 volumio volumio[844]: info: Discovery: Getting this device information Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:28 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 12:44:28 volumio volumio[844]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 07 12:44:28 volumio volumio[844]: SPOTIFY: BQBXS0VnmtD2kMypPWW_EKt7dxfa_Xr4WmpPI-biceqqat8puT-Xpk7A1szlw2OF8YX8p-4dey9kQDYsjhGwkaw0yGjD_w5xWLDVeatbaTY-N9vvePyavuZsI1CNngc7WsKITrKeqo3nCY29YMkdFvwD7blRXHPQboePf46a_rqsUYSAFxOdGUqp14Md4AYfhugSDRbecCWByDdfiMtRCNXTNodHePjFI_20__GmOjw2Ani5eRTTNUsL-jBLFU7o3-Ii3Jwlx_-iaIu1_8-i3_72d0sobcuW9XWPXH7tdz8uAw0 Sep 07 12:44:28 volumio volumio[844]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 07 12:44:28 volumio volumio[844]: info: New Spotify access token = BQBXS0VnmtD2kMypPWW_EKt7dxfa_Xr4WmpPI-biceqqat8puT-Xpk7A1szlw2OF8YX8p-4dey9kQDYsjhGwkaw0yGjD_w5xWLDVeatbaTY-N9vvePyavuZsI1CNngc7WsKITrKeqo3nCY29YMkdFvwD7blRXHPQboePf46a_rqsUYSAFxOdGUqp14Md4AYfhugSDRbecCWByDdfiMtRCNXTNodHePjFI_20__GmOjw2Ani5eRTTNUsL-jBLFU7o3-Ii3Jwlx_-iaIu1_8-i3_72d0sobcuW9XWPXH7tdz8uAw0 Sep 07 12:44:28 volumio volumio[844]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 07 12:44:28 volumio volumio[844]: info: Starting Shairport Sync Sep 07 12:44:28 volumio volumio[844]: info: Starting Shairport Sync Sep 07 12:44:28 volumio sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 07 12:44:28 volumio sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio volumio[844]: info: Starting Shairport Sync Sep 07 12:44:28 volumio sudo[1198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 07 12:44:28 volumio sudo[1198]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 07 12:44:28 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 07 12:44:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:28 volumio sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 07 12:44:28 volumio sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:28 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:28 volumio volumio[844]: verbose: New Socket.io Connection to 192.168.2.141:3000 from 192.168.2.106 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Sep 07 12:44:28 volumio go-librespot[1180]: time="2025-09-07T12:44:28+02:00" level=info msg="running go-librespot 0.3.2" Sep 07 12:44:28 volumio go-librespot[1180]: time="2025-09-07T12:44:28+02:00" level=debug msg="app state loaded" Sep 07 12:44:28 volumio go-librespot[1180]: time="2025-09-07T12:44:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 07 12:44:28 volumio volumio[844]: info: Asound.conf file unchanged, so no further update is needed Sep 07 12:44:28 volumio volumio[844]: info: Output device has changed, restarting MPD Sep 07 12:44:28 volumio sudo[1196]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:28 volumio sudo[1198]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 07 12:44:28 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 07 12:44:28 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 07 12:44:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:28 volumio sudo[1206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 07 12:44:28 volumio sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio volumio[844]: info: Output device has changed, restarting Shairport Sync Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:28 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:28 volumio sudo[1206]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:28 volumio sudo[1201]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:28 volumio sudo[1210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 07 12:44:28 volumio sudo[1210]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:28 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 07 12:44:28 volumio systemd[1]: mpd.service: Succeeded. Sep 07 12:44:28 volumio systemd[1]: Stopped Music Player Daemon. Sep 07 12:44:28 volumio volumio[844]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 07 12:44:29 volumio systemd[1]: Starting Music Player Daemon... Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:29 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 07 12:44:29 volumio volumio[844]: info: MPD Permissions set Sep 07 12:44:29 volumio volumio[844]: info: Shairport-Sync Started Sep 07 12:44:29 volumio volumio[844]: Error adding Membership: Error: addMembership EINVAL Sep 07 12:44:29 volumio volumio[844]: info: Shairport-Sync Started Sep 07 12:44:29 volumio volumio[844]: info: Shairport-Sync Started Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio sudo[1217]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 07 12:44:29 volumio sudo[1217]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 07 12:44:29 volumio sudo[1217]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio volumio[844]: info: Starting Shairport Sync Sep 07 12:44:29 volumio sudo[1228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 07 12:44:29 volumio sudo[1228]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 07 12:44:29 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 07 12:44:29 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 07 12:44:29 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:29 volumio volumio[844]: SPOTIFY: User informations: {"country":"FR","display_name":"Jeffdeleffe","email":"jfrancoismartin@wanadoo.fr","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/55f247nvmzkb9tqvcav8yvlvx"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/55f247nvmzkb9tqvcav8yvlvx","id":"55f247nvmzkb9tqvcav8yvlvx","images":[],"product":"premium","type":"user","uri":"spotify:user:55f247nvmzkb9tqvcav8yvlvx"} Sep 07 12:44:29 volumio volumio[844]: info: Spotify Successfully logged in Sep 07 12:44:29 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 07 12:44:29 volumio sudo[1228]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=info msg="zeroconf server listening on port 37961" Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 07 12:44:29 volumio volumio[844]: info: [1757241869342] CoreMusicLibrary::Adding element Spotify Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 12:44:29 volumio volumio[844]: Cannot find translation for source YouTube2 Sep 07 12:44:29 volumio volumio[844]: Cannot find translation for source YouTube Music Sep 07 12:44:29 volumio volumio[844]: Cannot find translation for source Spotify Sep 07 12:44:29 volumio volumio[844]: info: Shairport-Sync Started Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="obtained new client token: AABAMXKltW6I0oN0qSzB0iwCpPT05ajXVp2HCAbuaHrQxF78Y8rDjMDsHNjYc33XdURBaE//2sxuG4vqZ1QS1fcKvyFqpeJc7NoZeHcnz4d3yci3Qr6Qs69DOHUMSIys0GKrK34gc5W+7S6MqW12SMu2oET0w5cSDLL9ephqfJlsqQBpGAsEwmgqoeIkGO+Ksq8Jz3Td192oa9OXx/v4CLE0SNyz0wCCLuGOQc4jzRagR3y5ryk5e5A=" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="completed keyexchange" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="completed challenge" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=info msg="authenticated AP" username="55*********************vx" Sep 07 12:44:29 volumio volumio[844]: info: camilladsp service started and running in background, instance 1 Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=info msg="authenticated Login5" username="55*********************vx" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="initializing zeroconf session" username="55*********************vx" Sep 07 12:44:29 volumio volumio[844]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Sep 07 12:44:29 volumio volumio[844]: info: FusionDsp loaded Sep 07 12:44:29 volumio volumio[844]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="dealer connection opened" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=trace msg="starting accesspoint recv loop" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=trace msg="received accesspoint ping" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=trace msg="starting dealer recv loop" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=debug msg="received connection id: ODAyODBmYTctNzRj...Rjk0OTREQkM3RA==" Sep 07 12:44:29 volumio go-librespot[1180]: time="2025-09-07T12:44:29+02:00" level=trace msg="received accesspoint pong ack" Sep 07 12:44:29 volumio sudo[1245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Sep 07 12:44:29 volumio sudo[1245]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 07 12:44:29 volumio volumio[844]: info: FusionDsp - Reporting Fusion DSP Enabled Sep 07 12:44:29 volumio volumio[844]: info: Adding Signal Path Element [object Object] Sep 07 12:44:29 volumio volumio[844]: info: Adding fusiondspeq DSP Signal Path Element Sep 07 12:44:29 volumio volumio[844]: info: FusionDsp - ---- installed callbackRead Sep 07 12:44:29 volumio volumio[844]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 07 12:44:29 volumio systemd[1]: Started FusionDsp Daemon. Sep 07 12:44:29 volumio sudo[1245]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:30 volumio go-librespot[1180]: time="2025-09-07T12:44:30+02:00" level=debug msg="put connect state because NEW_DEVICE" Sep 07 12:44:30 volumio go-librespot[1180]: time="2025-09-07T12:44:30+02:00" level=debug msg="update volume requested to 65535/65535" Sep 07 12:44:30 volumio volumio[844]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 07 12:44:30 volumio volumio[844]: info: FusionDsp - {"Reload":{"result":"Ok"}} Sep 07 12:44:30 volumio go-librespot[1180]: time="2025-09-07T12:44:30+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 07 12:44:30 volumio go-librespot[1180]: time="2025-09-07T12:44:30+02:00" level=trace msg="emitting websocket event: volume" Sep 07 12:44:30 volumio volumio[844]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 07 12:44:30 volumio volumio[844]: info: CoreCommandRouter::volumioRetrievevolume Sep 07 12:44:30 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:30 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:30 volumio volumio[844]: info: CoreStateMachine::pushState Sep 07 12:44:30 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:30 volumio volumio[844]: info: CoreCommandRouter::volumioPushState Sep 07 12:44:30 volumio volumio[844]: error: [ytcr] VolumeControl failed to obtain volume from Volumio: Sep 07 12:44:30 volumio volumio[844]: (TypeError) Cannot read property 'vol' of undefined Sep 07 12:44:30 volumio volumio[844]: TypeError: Cannot read property 'vol' of undefined Sep 07 12:44:30 volumio volumio[844]: at VolumeControl.getVolume (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:56:42) Sep 07 12:44:30 volumio volumio[844]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Sep 07 12:44:30 volumio volumio[844]: at async VolumeControl.init (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:28:68) Sep 07 12:44:30 volumio volumio[844]: at async /data/plugins/music_service/ytcr/dist/index.js:326:13 Sep 07 12:44:30 volumio volumio[844]: error: Upnp client error: Error: This socket has been ended by the other party Sep 07 12:44:30 volumio mpd[1226]: Sep 07 12:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 07 12:44:31 volumio volumio[1120]: ..............................++++ Sep 07 12:44:31 volumio volumio[844]: info: go-librespot daemon successfully initialized Sep 07 12:44:31 volumio systemd[1]: Started Music Player Daemon. Sep 07 12:44:31 volumio volumio[844]: Upnp client error: Error: This socket has been ended by the other party Sep 07 12:44:31 volumio sudo[1147]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:31 volumio sudo[1137]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:31 volumio sudo[1210]: pam_unix(sudo:session): session closed for user root Sep 07 12:44:31 volumio volumio[844]: error: MPD error: The expression evaluated to a falsy value: Sep 07 12:44:31 volumio volumio[844]: assert.ok(self.idling) Sep 07 12:44:31 volumio volumio[844]: error: The expression evaluated to a falsy value: Sep 07 12:44:31 volumio volumio[844]: assert.ok(self.idling) Sep 07 12:44:31 volumio volumio[844]: error: MPD error: The expression evaluated to a falsy value: Sep 07 12:44:31 volumio volumio[844]: assert.ok(self.idling) Sep 07 12:44:31 volumio volumio[844]: error: The expression evaluated to a falsy value: Sep 07 12:44:31 volumio volumio[844]: assert.ok(self.idling) Sep 07 12:44:31 volumio volumio[844]: error: updateQueue error: null Sep 07 12:44:31 volumio volumio[844]: info: MPD running with PID1226 Sep 07 12:44:31 volumio volumio[844]: ,establishing connection Sep 07 12:44:31 volumio volumio[844]: error: updateQueue error: null Sep 07 12:44:31 volumio volumio[844]: info: Completed starting Core Plugins Sep 07 12:44:31 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:44:31 volumio volumio[844]: info: ----- MyVolumio plugins startup ---- Sep 07 12:44:31 volumio volumio[844]: info: ------------------------------------------- Sep 07 12:44:31 volumio volumio[844]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 07 12:44:33 volumio volumio-remote-updater[579]: [2025-09-07 12:44:33] [connect] Successful connection Sep 07 12:44:33 volumio volumio-remote-updater[579]: [2025-09-07 12:44:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1757241873 101 Sep 07 12:44:33 volumio volumio[844]: 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: 8 Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="handling transfer player command from 165cef114b22ee92b8aaa3aa751e9c89e60c1109" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:0dNBdAP6irPFlLpy0gzcbf" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=trace msg="fetched new page 0 with 163 items (list: 163)" uri="spotify:playlist:0dNBdAP6irPFlLpy0gzcbf" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="loading track (paused: false, position: 181977ms)" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=trace msg="emitting websocket event: will_play" Sep 07 12:44:34 volumio volumio[844]: info: Initializing connection to go-librespot Websocket Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=warning msg="original track has no formats, alternatives have a total of 8" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="selected format OGG_VORBIS_320 (2fd013c7b243fe5c29b82f745e6e4b44a1f7e759)" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="requested aes key for file 2fd013c7b243fe5c29b82f745e6e4b44a1f7e759, gid: 5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="new websocket client" Sep 07 12:44:34 volumio volumio[844]: info: Connection to go-librespot Websocket established Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="fetched first chunk of 24, total size is 12159332 bytes" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:34 volumio go-librespot[1180]: time="2025-09-07T12:44:34+02:00" level=debug msg="fetched chunk 1/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 2/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 15/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 17/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 3/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 14/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=trace msg="seek to 181977ms (diff: 114ms, samples: 8025185, bytes: 7343398)" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="created new output device" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="fetched chunk 16/23, size: 524288" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio volumio[844]: info: FusionDsp - ---- read samplerate, raw: Sep 07 12:44:35 volumio volumio[844]: error: FusionDsp - invalid sample rate Sep 07 12:44:35 volumio volumio[844]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=info msg="loaded track \"Pusherman\" (paused: false, position: 181977ms, duration: 299760ms, prefetched: false)" uri="spotify:track:5BAgs6E1WG3ugUyi5YvObY" Sep 07 12:44:35 volumio volumio[844]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 07 12:44:35 volumio volumio[844]: info: camilladsp stopping service pid 1239... Sep 07 12:44:35 volumio volumio[844]: info: camilladsp service terminated, instance 1 Sep 07 12:44:35 volumio volumio[844]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 07 12:44:35 volumio volumio[844]: info: camilladsp service started and running in background, instance 1 Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=trace msg="scheduling prefetch in 88s" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=trace msg="emitting websocket event: metadata" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=trace msg="emitting websocket event: active" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="sending successful reply for dealer request" Sep 07 12:44:35 volumio volumio[844]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5BAgs6E1WG3ugUyi5YvObY","name":"Pusherman","artist_names":["Curtis Mayfield"],"album_name":"The Very Best of Curtis Mayfield","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fa97c1cdac13a0d1fa9a8cf2","position":181977,"duration":299760,"release_date":"year:1997 month:1 day:1","track_number":8,"disc_number":1}} Sep 07 12:44:35 volumio volumio[844]: SPOTIFY: received: {"type":"active","data":null} Sep 07 12:44:35 volumio volumio[844]: info: Aligning Spotify Volume to Volumio Volume Sep 07 12:44:35 volumio volumio[844]: info: CoreCommandRouter::volumioGetState Sep 07 12:44:35 volumio volumio[844]: info: CorePlayQueue::getTrack 0 Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 07 12:44:35 volumio go-librespot[1180]: time="2025-09-07T12:44:35+02:00" level=trace msg="emitting websocket event: playing" Sep 07 12:44:35 volumio volumio[844]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5BAgs6E1WG3ugUyi5YvObY","resume":false,"play_origin":"playlist"}} Sep 07 12:44:35 volumio volumio[844]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 12:44:35 volumio volumio[844]: TypeError: Cannot read property 'service' of undefined Sep 07 12:44:35 volumio volumio[844]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Sep 07 12:44:35 volumio volumio[844]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Sep 07 12:44:35 volumio volumio[844]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Sep 07 12:44:35 volumio volumio[844]: at WebSocket.emit (events.js:315:20) Sep 07 12:44:35 volumio volumio[844]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Sep 07 12:44:35 volumio volumio[844]: at Receiver.emit (events.js:315:20) Sep 07 12:44:35 volumio volumio[844]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Sep 07 12:44:35 volumio volumio[844]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Sep 07 12:44:35 volumio volumio[844]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Sep 07 12:44:35 volumio volumio[844]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Sep 07 12:44:35 volumio volumio[844]: at writeOrBuffer (internal/streams/writable.js:358:12) Sep 07 12:44:35 volumio volumio[844]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Sep 07 12:44:35 volumio volumio[844]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Sep 07 12:44:35 volumio volumio[844]: at Socket.emit (events.js:315:20) Sep 07 12:44:35 volumio volumio[844]: at addChunk (internal/streams/readable.js:309:12) Sep 07 12:44:35 volumio volumio[844]: at readableAddChunk (internal/streams/readable.js:284:9) Sep 07 12:44:35 volumio volumio[844]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 12:44:35 volumio sudo[1291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-07 12:43 Sep 07 12:44:35 volumio sudo[1291]: 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="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"