-- Logs begin at Mon 2025-09-15 18:47:27 CEST, end at Wed 2025-09-17 21:16:37 CEST. -- Sep 17 21:15:02 severinelenceinte volumio[23825]: info: MYVOLUMIO Environment detected Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Plugin folders cleanup Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning into folder /volumio/app/plugins/ Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category audio_interface Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category miscellanea Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category music_service Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category plugins.json Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category system_controller Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category user_interface Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning into folder /data/plugins/ Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category music_service Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category system_controller Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Scanning category system_hardware Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Plugin folders cleanup completed Sep 17 21:15:02 severinelenceinte volumio[23825]: info: ------------------------------------------- Sep 17 21:15:02 severinelenceinte volumio[23825]: info: ----- Core plugins startup ---- Sep 17 21:15:02 severinelenceinte volumio[23825]: info: ------------------------------------------- Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Loading plugins from folder /volumio/app/plugins/ Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Adding plugin upnp to MyMusic Plugins Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Loading plugins from folder /data/plugins/ Sep 17 21:15:02 severinelenceinte volumio[23825]: info: Loading plugin "system"... Sep 17 21:15:03 severinelenceinte volumio[23825]: info: Loading plugin "appearance"... Sep 17 21:15:03 severinelenceinte volumio-remote-updater[361]: [2025-09-17 21:15:03] [connect] Successful connection Sep 17 21:15:07 severinelenceinte volumio[23825]: info: Loading plugin "network"... Sep 17 21:15:07 severinelenceinte volumio[23825]: info: Refreshing Cached IP Addresses Sep 17 21:15:07 severinelenceinte sudo[23851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 17 21:15:07 severinelenceinte sudo[23851]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:07 severinelenceinte sudo[23853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 17 21:15:07 severinelenceinte sudo[23851]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:07 severinelenceinte sudo[23853]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:07 severinelenceinte volumio[23825]: info: Loading plugin "services"... Sep 17 21:15:07 severinelenceinte volumio[23825]: info: Loading plugin "alsa_controller"... Sep 17 21:15:07 severinelenceinte sudo[23853]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:08 severinelenceinte sudo[23864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 17 21:15:08 severinelenceinte sudo[23864]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:08 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "wizard"... Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "networkfs"... Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Starting Udev Watcher for removable devices Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Ignoring mount for partition: boot Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Ignoring mount for partition: volumio Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Ignoring mount for partition: volumio_data Sep 17 21:15:08 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "volumio_command_line_client"... Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "upnp"... Sep 17 21:15:08 severinelenceinte volumio[23825]: info: [1758136508720] Starting Upmpd Daemon Sep 17 21:15:08 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "my_music"... Sep 17 21:15:08 severinelenceinte volumio[23825]: info: Loading plugin "mpd"... Sep 17 21:15:09 severinelenceinte sudo[23864]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:10 severinelenceinte volumio[23825]: info: Loading plugin "upnp_browser"... Sep 17 21:15:11 severinelenceinte volumio[23825]: info: Loading plugin "alarm-clock"... Sep 17 21:15:12 severinelenceinte volumio[23825]: info: Loading plugin "airplay_emulation"... Sep 17 21:15:12 severinelenceinte volumio[23825]: info: Starting Shairport Sync Sep 17 21:15:12 severinelenceinte volumio[23825]: info: Loading plugin "last_100"... Sep 17 21:15:12 severinelenceinte volumio[23825]: info: Loading plugin "webradio"... Sep 17 21:15:13 severinelenceinte volumio[23825]: info: Loading plugin "i2s_dacs"... Sep 17 21:15:13 severinelenceinte volumio[23825]: info: Loading plugin "volumiodiscovery"... Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** For more information see Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 17 21:15:13 severinelenceinte volumio[23825]: *** WARNING *** For more information see Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** For more information see Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 17 21:15:13 severinelenceinte node[23825]: *** WARNING *** For more information see Sep 17 21:15:13 severinelenceinte volumio[23825]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 17 21:15:13 severinelenceinte volumio[23825]: info: Discovery: Started advertising with name: Severinelenceinte Sep 17 21:15:13 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 17 21:15:13 severinelenceinte volumio[23825]: info: Loading plugin "soundcloud"... Sep 17 21:15:15 severinelenceinte volumio[23825]: info: Loading plugin "spop"... Sep 17 21:15:18 severinelenceinte volumio-remote-updater[361]: [2025-09-17 21:15:18] [connect] Successful connection Sep 17 21:15:21 severinelenceinte volumio[23825]: info: Loading plugin "ytmusic"... Sep 17 21:15:33 severinelenceinte volumio-remote-updater[361]: [2025-09-17 21:15:33] [connect] Successful connection Sep 17 21:15:37 severinelenceinte volumio[23825]: info: Loading plugin "gpio-buttons"... Sep 17 21:15:38 severinelenceinte volumio[23825]: info: GPIO-Buttons initialized Sep 17 21:15:38 severinelenceinte volumio[23825]: info: Loading plugin "outputs"... Sep 17 21:15:38 severinelenceinte volumio[23825]: info: Loading plugin "albumart"... Sep 17 21:15:39 severinelenceinte volumio[23825]: info: Plugin example_plugin is not enabled Sep 17 21:15:39 severinelenceinte volumio[23825]: info: Loading plugin "inputs"... Sep 17 21:15:39 severinelenceinte volumio[23825]: info: Loading plugin "updater_comm"... Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Plugin mpdemulation is not enabled Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Loading plugin "rest_api"... Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Loading plugin "websocket"... Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Starting Socket.io Server version 2.3.0 Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Plugin scheduledrestart is not enabled Sep 17 21:15:40 severinelenceinte volumio[23825]: info: Plugin gpio_control is not enabled Sep 17 21:15:41 severinelenceinte volumio[23825]: info: Loading i18n strings for locale fr Sep 17 21:15:41 severinelenceinte volumio[23825]: Updating browse sources language Sep 17 21:15:41 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:42 severinelenceinte volumio[23825]: Forking 1 albumart workers Sep 17 21:15:42 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 21:15:42 severinelenceinte volumio[23825]: info: CoreCommandRouter::initPlayerControls Sep 17 21:15:42 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:42 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:42 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 21:15:42 severinelenceinte volumio[23825]: Express server listening on port 3000 Sep 17 21:15:42 severinelenceinte volumio[23825]: [Metrics] WebUI: 46s 417.76ms Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreStateMachine::resetVolumioState Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreStateMachine::getcurrentVolume Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioRetrievevolume Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreStateMachine::pushState Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 17 21:15:43 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioPushState Sep 17 21:15:44 severinelenceinte sudo[23952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 17 21:15:44 severinelenceinte sudo[23952]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:44 severinelenceinte sudo[23952]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:44 severinelenceinte sudo[23966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 17 21:15:44 severinelenceinte sudo[23966]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:44 severinelenceinte sudo[23966]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:44 severinelenceinte volumio[23825]: info: Cannot read play queue from file Sep 17 21:15:44 severinelenceinte volumio[23825]: info: Volumio Network Manager: Network status updated: 2 Sep 17 21:15:45 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 1 Sep 17 21:15:45 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 2 Sep 17 21:15:45 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 3 Sep 17 21:15:45 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 4 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 5 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 6 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 7 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 8 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 9 Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 17 21:15:46 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:46 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to 192.168.1.61 from 192.168.1.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:141.0) Gecko/20100101 Firefox/141.0 Engine version: 3 Transport: polling Total Clients: 11 Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreStateMachine::setRepeat null single undefined Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreStateMachine::pushState Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioPushState Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreStateMachine::setRandom null Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreStateMachine::pushState Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioPushState Sep 17 21:15:47 severinelenceinte volumio[23825]: info: Setting Device type: Raspberry PI Sep 17 21:15:47 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 17 21:15:47 severinelenceinte volumio[23825]: info: Completed loading Core Plugins Sep 17 21:15:47 severinelenceinte volumio[23825]: info: Preparing to generate the ALSA configuration file Sep 17 21:15:48 severinelenceinte volumio[23825]: info: Discovery: adding c0ae6df8-119b-4be7-b5a2-ec051bf8882b Sep 17 21:15:48 severinelenceinte sudo[24000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 17 21:15:48 severinelenceinte volumio[23825]: info: Discovery: Found device Severinelenceinte Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:48 severinelenceinte sudo[24000]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:48 severinelenceinte sudo[24000]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetVisibleSources Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 17 21:15:48 severinelenceinte volumio[23825]: info: Received Get System Info Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 17 21:15:48 severinelenceinte volumio[23825]: info: Discovery: Getting this device information Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:15:48 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:15:48 severinelenceinte volumio-remote-updater[361]: [2025-09-17 21:15:48] [connect] Successful connection Sep 17 21:15:48 severinelenceinte volumio[23825]: info: Listing playlists Sep 17 21:15:49 severinelenceinte volumio[23825]: info: Upmpdcli Daemon Started Sep 17 21:15:49 severinelenceinte volumio-remote-updater[361]: [2025-09-17 21:15:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1758136548 101 Sep 17 21:15:49 severinelenceinte volumio[23825]: 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: 12 Sep 17 21:15:49 severinelenceinte volumio[23825]: info: Asound.conf file written Sep 17 21:15:49 severinelenceinte volumio[23825]: Starting albumart workers Sep 17 21:15:50 severinelenceinte sudo[24017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 17 21:15:50 severinelenceinte sudo[24017]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:50 severinelenceinte sudo[24017]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:50 severinelenceinte volumio[23825]: info: Output device has changed, restarting MPD Sep 17 21:15:50 severinelenceinte volumio[23825]: info: Output device has changed, restarting Shairport Sync Sep 17 21:15:50 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:50 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:50 severinelenceinte sudo[24022]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 17 21:15:50 severinelenceinte sudo[24022]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:50 severinelenceinte sudo[24022]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:50 severinelenceinte sudo[24024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 17 21:15:50 severinelenceinte sudo[24024]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:51 severinelenceinte systemd[1]: Stopping Music Player Daemon... Sep 17 21:15:51 severinelenceinte systemd[1]: mpd.service: Succeeded. Sep 17 21:15:51 severinelenceinte systemd[1]: Stopped Music Player Daemon. Sep 17 21:15:51 severinelenceinte systemd[1]: Starting Music Player Daemon... Sep 17 21:15:51 severinelenceinte volumio[23825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 17 21:15:51 severinelenceinte volumio[23825]: info: ___________ START PLUGINS ___________ Sep 17 21:15:51 severinelenceinte volumio[23825]: info: ControllerMpd::onStart: Initializing MPD Sep 17 21:15:51 severinelenceinte volumio[23825]: info: Creating MPD Configuration file Sep 17 21:15:51 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 17 21:15:51 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 17 21:15:51 severinelenceinte sudo[24030]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 17 21:15:51 severinelenceinte sudo[24030]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:51 severinelenceinte volumio[23825]: info: [1758136551932] CoreMusicLibrary::Adding element Serveurs Média Sep 17 21:15:51 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:51 severinelenceinte sudo[24030]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:52 severinelenceinte sudo[24032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 17 21:15:52 severinelenceinte sudo[24032]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:52 severinelenceinte sudo[24032]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:52 severinelenceinte sudo[24034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 17 21:15:52 severinelenceinte sudo[24034]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:52 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:52 severinelenceinte systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 17 21:15:52 severinelenceinte systemd[1]: mpd.service: Succeeded. Sep 17 21:15:52 severinelenceinte systemd[1]: Stopped Music Player Daemon. Sep 17 21:15:52 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:52 severinelenceinte systemd[1]: Starting Music Player Daemon... Sep 17 21:15:53 severinelenceinte volumio[23825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 17 21:15:53 severinelenceinte sudo[24039]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 17 21:15:53 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:53 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:53 severinelenceinte sudo[24039]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:15:53 severinelenceinte sudo[24039]: pam_unix(sudo:session): session closed for user root Sep 17 21:15:54 severinelenceinte volumio[23825]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 17 21:15:54 severinelenceinte volumio[23825]: info: [1758136554054] CoreMusicLibrary::Adding element Last_100 Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 17 21:15:54 severinelenceinte volumio[23825]: info: [1758136554120] CoreMusicLibrary::Adding element Webradio Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 17 21:15:54 severinelenceinte volumio[23825]: info: Initializing BBC Radios Sep 17 21:15:54 severinelenceinte volumio[23825]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Sep 17 21:15:54 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 17 21:15:55 severinelenceinte volumio[23825]: info: [1758136555262] CoreMusicLibrary::Adding element SoundCloud Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:55 severinelenceinte volumio[23825]: Cannot find translation for source SoundCloud Sep 17 21:15:55 severinelenceinte volumio[23825]: info: Creating Spotify config file Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 17 21:15:55 severinelenceinte volumio[23825]: info: [1758136555880] CoreMusicLibrary::Adding element YouTube Music Sep 17 21:15:55 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 17 21:15:55 severinelenceinte volumio[23825]: Cannot find translation for source SoundCloud Sep 17 21:15:55 severinelenceinte volumio[23825]: Cannot find translation for source YouTube Music Sep 17 21:15:56 severinelenceinte volumio[23825]: info: GPIO-Buttons: Reading config and creating triggers... Sep 17 21:15:56 severinelenceinte volumio[23825]: info: Volumio Calling Home Sep 17 21:15:56 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:56+02:00" level=debug msg="obtained new client token: AACJE/dKmDALOpzYALwBIFphRhYA6aWVA5AV8eVnDKWK56ijutqF8+KVz3vRzkgMtZfdWBO7teRm1WxZMQbP36bZDV3J7v8rd7Wks4RQkFvwnVQwqQimv94kOoPEwGQOwG07MPDuUGuOn0E9BFgoQO4WpqAf0SSy/2eug4S13yfx4cwofmKg3kr8t6A5COtqJUnheOmzhGcez01feP3KupZY6V8x3lza84KTRhZAmbp1LEBCsldqjM4uHA==" Sep 17 21:15:56 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:56+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="completed keyexchange" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="completed challenge" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=info msg="authenticated AP" username="at*********************s9" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=info msg="authenticated Login5" username="at*********************s9" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=info msg="accepted zeroconf from iPhone" username="at*********************s9" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="dealer connection opened" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=trace msg="starting accesspoint recv loop" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=trace msg="starting dealer recv loop" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=trace msg="received accesspoint ping" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="received connection id: OThkYWI3NWUtZjM5...NDk3NjUzRTA5Qw==" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=trace msg="received accesspoint pong ack" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="put connect state because NEW_DEVICE" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="update volume requested to 65535/65535" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=trace msg="emitting websocket event: volume" Sep 17 21:15:57 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:57+02:00" level=debug msg="handling transfer player command from 0ebd5afce85b1dcec0e7053230397fec2a8e07f2" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=warning msg="failed seeking to track in context spotify:playlist:37i9dQZF1E3848s5x0EzmP" error="could not find track" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="shuffled context with seed 9590091556711290146 (len: 50, keep: 31)" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="loading track (paused: true, position: 15662ms)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=trace msg="emitting websocket event: will_play" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1368" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="selected format OGG_VORBIS_320 (f073e408a4d2b6158c79220cce892d5432973cba)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="requested aes key for file f073e408a4d2b6158c79220cce892d5432973cba, gid: 4joiWvli4qJVEW6qZV2i2J" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:15:58 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1133" Sep 17 21:15:59 severinelenceinte volumio[23825]: info: GPIO-Buttons started Sep 17 21:15:59 severinelenceinte go-librespot[23538]: time="2025-09-17T21:15:59+02:00" level=debug msg="fetched first chunk of 11, total size is 5300928 bytes" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:02 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:02+02:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="fetched chunk 4/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=trace msg="seek to 15662ms (diff: 104ms, samples: 690694, bytes: 655007)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="created new output device" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=info msg="loaded track \"All My Loving - Remastered 2009\" (paused: true, position: 15662ms, duration: 127853ms, prefetched: false)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte volumio[23825]: info: MPD Permissions set Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=trace msg="emitting websocket event: metadata" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=trace msg="emitting websocket event: active" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="sending successful reply for dealer request" Sep 17 21:16:03 severinelenceinte volumio[23825]: info: Volumio called home Sep 17 21:16:03 severinelenceinte volumio[23825]: info: Spotify config file written Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:03 severinelenceinte go-librespot[23538]: time="2025-09-17T21:16:03+02:00" level=trace msg="emitting websocket event: paused" Sep 17 21:16:03 severinelenceinte sudo[24091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 17 21:16:03 severinelenceinte sudo[24091]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:03 severinelenceinte volumio[23825]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte systemd[1]: Stopping go-librespot Daemon... Sep 17 21:16:04 severinelenceinte systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 17 21:16:04 severinelenceinte systemd[1]: go-librespot-daemon.service: Succeeded. Sep 17 21:16:04 severinelenceinte systemd[1]: Stopped go-librespot Daemon. Sep 17 21:16:04 severinelenceinte systemd[1]: Started go-librespot Daemon. Sep 17 21:16:04 severinelenceinte sudo[24091]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:04 severinelenceinte go-librespot[24094]: go-librespot daemon starting... Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:04+02:00" level=info msg="running go-librespot 0.3.2" Sep 17 21:16:04 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:04+02:00" level=debug msg="app state loaded" Sep 17 21:16:04 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:04+02:00" level=debug msg="stored credentials not found" Sep 17 21:16:04 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 17 21:16:04 severinelenceinte volumio[23825]: info: No need to fix Spotify hosts Sep 17 21:16:06 severinelenceinte mpd_monitor.sh[368]: MPD Monitor Service: MPD Appears to be inactive, restarting Sep 17 21:16:06 severinelenceinte systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 17 21:16:06 severinelenceinte systemd[1]: mpd.service: Failed with result 'protocol'. Sep 17 21:16:06 severinelenceinte systemd[1]: Failed to start Music Player Daemon. Sep 17 21:16:06 severinelenceinte sudo[24024]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:06 severinelenceinte sudo[24034]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:06 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Sep 17 21:16:06 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 17 21:16:06 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 17 21:16:06 severinelenceinte systemd[1]: Starting Music Player Daemon... Sep 17 21:16:07 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:07+02:00" level=info msg="zeroconf server listening on port 39279" Sep 17 21:16:07 severinelenceinte volumio[23825]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Sep 17 21:16:07 severinelenceinte volumio[23825]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Sep 17 21:16:07 severinelenceinte volumio[23825]: See "systemctl status mpd.service" and "journalctl -xe" for details. Sep 17 21:16:07 severinelenceinte volumio[23825]: info: Completed starting Core Plugins Sep 17 21:16:07 severinelenceinte volumio[23825]: info: ------------------------------------------- Sep 17 21:16:07 severinelenceinte volumio[23825]: info: ----- MyVolumio plugins startup ---- Sep 17 21:16:07 severinelenceinte volumio[23825]: info: ------------------------------------------- Sep 17 21:16:07 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 17 21:16:07 severinelenceinte volumio[23825]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Sep 17 21:16:07 severinelenceinte volumio[23825]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Sep 17 21:16:07 severinelenceinte volumio[23825]: See "systemctl status mpd.service" and "journalctl -xe" for details. Sep 17 21:16:07 severinelenceinte volumio[23825]: info: Starting Shairport Sync Sep 17 21:16:07 severinelenceinte volumio[23825]: info: Starting Shairport Sync Sep 17 21:16:07 severinelenceinte volumio[23825]: info: Starting Shairport Sync Sep 17 21:16:07 severinelenceinte sudo[24112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 17 21:16:07 severinelenceinte sudo[24112]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:07 severinelenceinte sudo[24110]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 17 21:16:07 severinelenceinte sudo[24110]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:07 severinelenceinte sudo[24110]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:07 severinelenceinte sudo[24114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 17 21:16:07 severinelenceinte sudo[24114]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:07 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:16:07 severinelenceinte systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 17 21:16:07 severinelenceinte systemd[1]: shairport-sync.service: Succeeded. Sep 17 21:16:07 severinelenceinte systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:08 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:16:08 severinelenceinte systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:08 severinelenceinte sudo[24112]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:08 severinelenceinte sudo[24118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 17 21:16:08 severinelenceinte sudo[24118]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:08 severinelenceinte systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 17 21:16:08 severinelenceinte systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 17 21:16:08 severinelenceinte systemd[1]: shairport-sync.service: Succeeded. Sep 17 21:16:08 severinelenceinte systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:08 severinelenceinte systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:08 severinelenceinte sudo[24114]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:08 severinelenceinte volumio[23825]: info: Shairport-Sync Started Sep 17 21:16:08 severinelenceinte systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 17 21:16:08 severinelenceinte volumio[23825]: Error adding Membership: Error: addMembership EINVAL Sep 17 21:16:08 severinelenceinte systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 17 21:16:08 severinelenceinte systemd[1]: shairport-sync.service: Succeeded. Sep 17 21:16:08 severinelenceinte systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:08 severinelenceinte volumio[23825]: info: Shairport-Sync Started Sep 17 21:16:08 severinelenceinte systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 17 21:16:09 severinelenceinte sudo[24118]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:09 severinelenceinte volumio[23825]: info: Shairport-Sync Started Sep 17 21:16:09 severinelenceinte volumio[23825]: info: go-librespot daemon successfully initialized Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="obtained new client token: AAB8Q3t/7BI2idP+TCaGmgxgpir6dD738JgK/A/sOvpAK+Af6kIdOXH727BbLtchyYGr6pMH9f/z7GT8Z7RYaxn9oFI6n8g8KynHBPUdBSCubPZQHQQlNhxVihH3raW6Fd+7l39pftYgJmP0IMVqboCvXVzMHfvCWxBCOZLcAuzXlQREvZWO9zDc+xfSWuqrwL8zV5qxmeJEuBua9hhVZiKHFMUIgI8x5iw5JE4/1Gyk6f7jVkJDu8g=" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="completed keyexchange" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="completed challenge" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=info msg="authenticated AP" username="at*********************s9" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=info msg="authenticated Login5" username="at*********************s9" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=info msg="accepted zeroconf from iPhone" username="at*********************s9" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="dealer connection opened" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=trace msg="starting accesspoint recv loop" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=trace msg="starting dealer recv loop" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=trace msg="received accesspoint ping" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 17 21:16:11 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:11+02:00" level=debug msg="received connection id: OTRmMWU0YTQtMjdj...Q0M5NEE0NDQyQQ==" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="put connect state because NEW_DEVICE" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="update volume requested to 65535/65535" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=trace msg="received accesspoint pong ack" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=trace msg="emitting websocket event: volume" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="handling transfer player command from 0ebd5afce85b1dcec0e7053230397fec2a8e07f2" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=warning msg="failed seeking to track in context spotify:playlist:37i9dQZF1E3848s5x0EzmP" error="could not find track" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="shuffled context with seed 16381022176850306359 (len: 50, keep: 16)" uri="spotify:playlist:37i9dQZF1E3848s5x0EzmP" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="loading track (paused: true, position: 15662ms)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=trace msg="emitting websocket event: will_play" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="selected format OGG_VORBIS_320 (f073e408a4d2b6158c79220cce892d5432973cba)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="requested aes key for file f073e408a4d2b6158c79220cce892d5432973cba, gid: 4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:12 severinelenceinte volumio[23825]: info: Initializing connection to go-librespot Websocket Sep 17 21:16:12 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:12+02:00" level=debug msg="new websocket client" Sep 17 21:16:12 severinelenceinte volumio[23825]: info: Connection to go-librespot Websocket established Sep 17 21:16:13 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:13+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:14 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:14+02:00" level=debug msg="fetched first chunk of 11, total size is 5300928 bytes" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Getting Spotify volume Sep 17 21:16:16 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:16+02:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 17 21:16:16 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:16+02:00" level=trace msg="seek to 15662ms (diff: 104ms, samples: 690694, bytes: 655007)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:16 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:16+02:00" level=debug msg="created new output device" Sep 17 21:16:16 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:16+02:00" level=info msg="loaded track \"All My Loving - Remastered 2009\" (paused: true, position: 15662ms, duration: 127853ms, prefetched: false)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin bluetooth to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin multiroom to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin metavolumio to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin cd_controller to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 17 21:16:16 severinelenceinte volumio[23825]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 17 21:16:17 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=trace msg="emitting websocket event: metadata" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=trace msg="emitting websocket event: active" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="sending successful reply for dealer request" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="fetched chunk 4/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=trace msg="emitting websocket event: paused" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="handling resume player command from 0ebd5afce85b1dcec0e7053230397fec2a8e07f2" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=trace msg="seek to 15662ms (diff: 104ms, samples: 690694, bytes: 655007)" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:4joiWvli4qJVEW6qZV2i2J" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="resume track at 15558ms" Sep 17 21:16:17 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:18 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:18+02:00" level=trace msg="scheduling prefetch in 82s" Sep 17 21:16:18 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:18+02:00" level=debug msg="sending successful reply for dealer request" Sep 17 21:16:18 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:18 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:18+02:00" level=trace msg="emitting websocket event: playing" Sep 17 21:16:21 severinelenceinte mpd[24120]: Sep 17 21:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 17 21:16:21 severinelenceinte systemd[1]: Started Music Player Daemon. Sep 17 21:16:21 severinelenceinte mpd_monitor.sh[368]: MPD Monitor Service: MPD restarted due to no mpc output. Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=debug msg="handling pause player command from 0ebd5afce85b1dcec0e7053230397fec2a8e07f2" Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=debug msg="pause track at 21076ms" Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=debug msg="sending successful reply for dealer request" Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 17 21:16:23 severinelenceinte go-librespot[24094]: time="2025-09-17T21:16:23+02:00" level=trace msg="emitting websocket event: paused" Sep 17 21:16:25 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 17 21:16:25 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 17 21:16:25 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:16:25 severinelenceinte volumio[23825]: info: Starting MyVolumio Remote Streaming Endpoints Sep 17 21:16:26 severinelenceinte volumio[23825]: info: MyVolumio login type: Token Sep 17 21:16:26 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 17 21:16:26 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 17 21:16:30 severinelenceinte volumio[23825]: info: Starting Streaming Service Transparent Proxy Sep 17 21:16:30 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 17 21:16:30 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 17 21:16:30 severinelenceinte volumio[23825]: info: Streaming services startup Sep 17 21:16:30 severinelenceinte volumio[23825]: info: Starting Streaming Daemon Sep 17 21:16:30 severinelenceinte sudo[24168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 17 21:16:30 severinelenceinte sudo[24168]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:30 severinelenceinte sudo[24168]: pam_unix(sudo:session): session closed for user root Sep 17 21:16:30 severinelenceinte volumio[23825]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 17 21:16:31 severinelenceinte volumio[23825]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 17 21:16:31 severinelenceinte volumio[23825]: info: Spotify volume: 100 Sep 17 21:16:31 severinelenceinte volumio[23825]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4joiWvli4qJVEW6qZV2i2J","name":"All My Loving - Remastered 2009","artist_names":["The Beatles"],"album_name":"With The Beatles (Remastered)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02608a63ad5b18e99da94a3f73","position":15662,"duration":127853,"release_date":"year:1963 month:11 day:22","track_number":3,"disc_number":1}} Sep 17 21:16:31 severinelenceinte volumio[23825]: SPOTIFY: received: {"type":"active","data":null} Sep 17 21:16:31 severinelenceinte volumio[23825]: info: Aligning Spotify Volume to Volumio Volume Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CoreCommandRouter::volumioGetState Sep 17 21:16:31 severinelenceinte volumio[23825]: info: CorePlayQueue::getTrack 0 Sep 17 21:16:31 severinelenceinte volumio[23825]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4joiWvli4qJVEW6qZV2i2J","play_origin":"playlist/ondemand"}} Sep 17 21:16:31 severinelenceinte volumio[23825]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 21:16:31 severinelenceinte volumio[23825]: TypeError: Cannot read property 'service' of undefined Sep 17 21:16:31 severinelenceinte volumio[23825]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Sep 17 21:16:31 severinelenceinte volumio[23825]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Sep 17 21:16:31 severinelenceinte volumio[23825]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Sep 17 21:16:31 severinelenceinte volumio[23825]: at WebSocket.emit (events.js:315:20) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.emit (events.js:315:20) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Sep 17 21:16:31 severinelenceinte volumio[23825]: at writeOrBuffer (internal/streams/writable.js:358:12) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Sep 17 21:16:31 severinelenceinte volumio[23825]: at Socket.emit (events.js:315:20) Sep 17 21:16:31 severinelenceinte volumio[23825]: at addChunk (internal/streams/readable.js:309:12) Sep 17 21:16:31 severinelenceinte volumio[23825]: at readableAddChunk (internal/streams/readable.js:284:9) Sep 17 21:16:31 severinelenceinte volumio[23825]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 17 21:16:33 severinelenceinte sudo[24199]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/nano /etc/asound.conf Sep 17 21:16:33 severinelenceinte sudo[24199]: pam_unix(sudo:session): session opened for user root by volumio(uid=0) Sep 17 21:16:37 severinelenceinte sudo[24202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-17 21:15 Sep 17 21:16:37 severinelenceinte sudo[24202]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 17 21:16:37 severinelenceinte sudo[24199]: pam_unix(sudo:session): session closed for user root 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"