Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: [FUNC] onStart Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Mar 24 23:53:00 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 24 23:53:00 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 24 23:53:00 musicvolumio volumio[3002]: info: Preparing CD Folders Mar 24 23:53:00 musicvolumio volumio[3002]: info: Adding CD REST API Endpoints Mar 24 23:53:00 musicvolumio volumio[3002]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 24 23:53:00 musicvolumio volumio[3002]: info: Starting UDEV Watcher for CD Mar 24 23:53:00 musicvolumio volumio[3002]: info: Detecting CD presence with UDEV Mar 24 23:53:00 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 24 23:53:00 musicvolumio bluetoothd[897]: Path / reserved for Adv Monitor app :1.56 Mar 24 23:53:00 musicvolumio bluetoothd[897]: Adv Monitor app :1.56 disconnected from D-Bus Mar 24 23:53:05 musicvolumio volumio[3002]: warn: [cd-plugin] cdspeedctl: device or media not ready Mar 24 23:53:05 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 24 23:53:05 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 24 23:53:05 musicvolumio volumio[3002]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 24 23:53:05 musicvolumio volumio[3002]: info: Adding TIDAL REST API Endpoints Mar 24 23:53:05 musicvolumio volumio[3002]: info: Stopping AccessToken refresher cron for QOBUZ Mar 24 23:53:05 musicvolumio sudo[3642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 24 23:53:05 musicvolumio sudo[3642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio volumio[3002]: info: AccessToken refresher cron started for QOBUZ Mar 24 23:53:05 musicvolumio volumio[3002]: info: Adding QOBUZ REST API Endpoints Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 24 23:53:05 musicvolumio volumio[3002]: info: Setting Geolocation for MyVolumio to eu6 Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio volumio[3002]: info: Setting Geolocation for MyVolumio to eu6 Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:05 musicvolumio sudo[3642]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Mar 24 23:53:05 musicvolumio sudo[3647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 24 23:53:05 musicvolumio sudo[3647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:53:05 musicvolumio sudo[3656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3656]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio sudo[3658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:53:05 musicvolumio sudo[3658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3658]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Mar 24 23:53:05 musicvolumio sudo[3647]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Mar 24 23:53:05 musicvolumio volumiobt[3661]: INFO [BTSTART] Ensuring Bluetooth directory exists... Mar 24 23:53:05 musicvolumio volumio[3002]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Mar 24 23:53:05 musicvolumio sudo[3662]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Mar 24 23:53:05 musicvolumio sudo[3662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3662]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio sudo[3664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 24 23:53:05 musicvolumio sudo[3664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Mar 24 23:53:05 musicvolumio sudo[3666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:05 musicvolumio sudo[3666]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio volumiobt[3669]: INFO [BTSTART] Powering on Bluetooth if needed... Mar 24 23:53:05 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:05 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:05 musicvolumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 24 23:53:05 musicvolumio sudo[3664]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:05 musicvolumio volumio[3002]: info: Remote SSH Started Mar 24 23:53:05 musicvolumio autossh[3673]: port set to 0, monitoring disabled Mar 24 23:53:05 musicvolumio autossh[3673]: starting ssh (count 1) Mar 24 23:53:05 musicvolumio autossh[3673]: ssh child pid is 3676 Mar 24 23:53:05 musicvolumio bluetoothd[897]: Adv Monitor app :1.58 disconnected from D-Bus Mar 24 23:53:05 musicvolumio volumiobt[3677]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Mar 24 23:53:05 musicvolumio volumiobt[3678]: [198B blob data] Mar 24 23:53:05 musicvolumio volumiobt[3678]: [162B blob data] Mar 24 23:53:05 musicvolumio volumiobt[3678]: [162B blob data] Mar 24 23:53:05 musicvolumio volumiobt[3678]: [162B blob data] Mar 24 23:53:05 musicvolumio volumiobt[3678]: [118B blob data] Mar 24 23:53:05 musicvolumio volumiobt[3678]: [65-3E-79-80-B7-5A]> discoverable on Mar 24 23:53:05 musicvolumio volumiobt[3678]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Mar 24 23:53:05 musicvolumio volumiobt[3678]: [65-3E-79-80-B7-5A]> pairable on Mar 24 23:53:05 musicvolumio volumiobt[3678]: [136B blob data] Mar 24 23:53:05 musicvolumio bluetoothd[897]: Path / reserved for Adv Monitor app :1.59 Mar 24 23:53:05 musicvolumio bluetoothd[897]: Adv Monitor app :1.59 disconnected from D-Bus Mar 24 23:53:05 musicvolumio volumiobt[3678]: [65-3E-79-80-B7-5A]> Mar 24 23:53:05 musicvolumio volumiobt[3679]: INFO [BTSTART] Registering Bluetooth agent... Mar 24 23:53:05 musicvolumio volumiobt[3680]: [NEW] Media /org/bluez/hci0 Mar 24 23:53:05 musicvolumio volumiobt[3680]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio volumiobt[3680]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio volumiobt[3680]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio bluetoothd[897]: Adv Monitor app :1.60 disconnected from D-Bus Mar 24 23:53:05 musicvolumio volumiobt[3681]: No agent is registered Mar 24 23:53:05 musicvolumio volumiobt[3681]: [NEW] Media /org/bluez/hci0 Mar 24 23:53:05 musicvolumio volumiobt[3681]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio volumiobt[3681]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio volumiobt[3681]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Mar 24 23:53:05 musicvolumio volumio[3002]: info: Successfully Added MyVolumio device Mar 24 23:53:05 musicvolumio bluetoothd[897]: Adv Monitor app :1.61 disconnected from D-Bus Mar 24 23:53:05 musicvolumio volumiobt[3682]: INFO [BTSTART] Agent registered successfully. Mar 24 23:53:05 musicvolumio volumiobt[3685]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Mar 24 23:53:05 musicvolumio volumiossh-tunnel[3676]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts. Mar 24 23:53:05 musicvolumio kernel: hwmon hwmon1: Undervoltage detected! Mar 24 23:53:05 musicvolumio sudo[3684]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:53:05 musicvolumio volumio[3002]: verbose: New Socket.io Connection to 192.168.0.75 from 192.168.0.214 UA: Mozilla/5.0 (Linux; Android 16; 25010PN30G Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Mar 24 23:53:05 musicvolumio sudo[3684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio volumio[3002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 24 23:53:06 musicvolumio sudo[3684]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio sudo[3688]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:53:06 musicvolumio sudo[3688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio sudo[3688]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: Listing playlists Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreStateMachine::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: Successfully Added MyVolumio device Mar 24 23:53:06 musicvolumio volumio[3002]: info: Updating MyVolumio device info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: info: Updating MyVolumio device info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 23:53:06 musicvolumio volumio[3002]: verbose: New Socket.io Connection to 192.168.0.75 from 192.168.0.214 UA: Mozilla/5.0 (Linux; Android 16; 25010PN30G Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:53:06 musicvolumio sudo[3694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:53:06 musicvolumio sudo[3694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio sudo[3696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:53:06 musicvolumio sudo[3694]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio sudo[3696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio sudo[3696]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: Listing playlists Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreStateMachine::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:53:06 musicvolumio volumio[3002]: info: Successfully Updated MyVolumio device Mar 24 23:53:06 musicvolumio volumio[3002]: verbose: New Socket.io Connection to 192.168.0.75 from 192.168.0.214 UA: Mozilla/5.0 (Linux; Android 16; 25010PN30G Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:53:06 musicvolumio sudo[3700]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:53:06 musicvolumio sudo[3700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio sudo[3700]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio sudo[3702]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:53:06 musicvolumio sudo[3702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:06 musicvolumio sudo[3702]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:53:06 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:06 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:06 musicvolumio volumio[3002]: info: Listing playlists Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CoreStateMachine::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: CorePlayQueue::getQueue Mar 24 23:53:06 musicvolumio volumio[3002]: info: Successfully Updated MyVolumio device Mar 24 23:53:07 musicvolumio volumio[3002]: verbose: New Socket.io Connection to 192.168.0.75 from 192.168.0.214 UA: Mozilla/5.0 (Linux; Android 16; 25010PN30G Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:53:07 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:07 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:53:07 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:07 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Connecting to system D-Bus Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Connected to system D-Bus Mar 24 23:53:07 musicvolumio volumio[3002]: info: Listing playlists Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetQueue Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreStateMachine::getQueue Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getQueue Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Mar 24 23:53:07 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:07 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:07 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Enabled Discoverable mode Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Agent registered at /local/a2dpagent Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] Agent set as default Mar 24 23:53:07 musicvolumio volumiobt[3686]: 2026-03-24 23:53:07 a2dp-agent [INFO] A2DP agent running, waiting for connections... Mar 24 23:53:07 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:53:08 musicvolumio volumio[3002]: info: TidalConnect service stoped! Mar 24 23:53:08 musicvolumio volumio[3002]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 24 23:53:08 musicvolumio volumio[3002]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 24 23:53:08 musicvolumio sudo[3717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 24 23:53:08 musicvolumio sudo[3717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:08 musicvolumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Mar 24 23:53:08 musicvolumio sudo[3717]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:08 musicvolumio volumio[3002]: info: Executing endpoint tc_getconfig Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 24 23:53:08 musicvolumio vtcs[3720]: STARTING TidalConnect services, version: 1.6.1 Mar 24 23:53:08 musicvolumio vtcs[3720]: STARTED TidalConnect services. Mar 24 23:53:08 musicvolumio volumio[3002]: info: Executing endpoint tc_connect Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 24 23:53:08 musicvolumio volumio[3002]: info: Connecting to TidalConnect Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::servicePushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Mar 24 23:53:08 musicvolumio volumio[3002]: verbose: CURRENT POSITION 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::syncState stateService stop Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::syncState currentStatus stop Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: No code Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::servicePushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Mar 24 23:53:08 musicvolumio volumio[3002]: verbose: CURRENT POSITION 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::syncState stateService stop Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::syncState currentStatus stop Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: No code Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreStateMachine::pushState Mar 24 23:53:08 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:08 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioPushState Mar 24 23:53:08 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:08.996Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:08 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:08.997Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:08 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:08.998Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:08 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:08.998Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.001Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.001Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.002Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.003Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.003Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.004Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.004Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" state=STATUS_STOPPED positionMs=0 volume=86 Mar 24 23:53:09 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:09.005Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.214:57286 @ 0x2206c60" id= title= Mar 24 23:53:11 musicvolumio volumio[3002]: info: TidalConnect service started! Mar 24 23:53:12 musicvolumio kernel: hwmon hwmon1: Voltage normalised Mar 24 23:53:12 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:53:12 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 23:53:15 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 23:53:16 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 23:53:16 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 23:53:17 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 23:53:30 musicvolumio volumio[3002]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Mar 24 23:53:30 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:30.934Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio[3002]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Mar 24 23:53:33 musicvolumio volumio[3002]: info: Folder /tmp/plugins removed Mar 24 23:53:33 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:33.086Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:33.605Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio[3002]: info: Check plugin dependencies Mar 24 23:53:33 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 23:53:33 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:33.659Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio[3002]: info: Checking if plugin already exists Mar 24 23:53:33 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:33.663Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio[3002]: info: Rename folder Mar 24 23:53:33 musicvolumio volumio[3002]: info: Folder /tmp/downloaded_plugin.zip removed Mar 24 23:53:33 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:33.682Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:33 musicvolumio volumio[3002]: info: Move to category Mar 24 23:53:34 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:34.325Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:34 musicvolumio volumio[3002]: info: Checking if install.sh is present Mar 24 23:53:34 musicvolumio volumio[3002]: info: Executing install.sh Mar 24 23:53:34 musicvolumio sudo[3798]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Mar 24 23:53:34 musicvolumio sudo[3798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:34 musicvolumio volumio[3002]: info: Installing Go-librespot Mar 24 23:53:34 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:34.390Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:34 musicvolumio volumio[3002]: info: Checking old vollibrespot installs Mar 24 23:53:34 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:34.404Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:34 musicvolumio systemd[1]: Reloading. Mar 24 23:53:35 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:35 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:35 musicvolumio volumio[3002]: info: Downloading daemon Mar 24 23:53:35 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:35.389Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:37 musicvolumio volumio[3002]: info: Creating directories Mar 24 23:53:37 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:37.144Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:37 musicvolumio volumio[3002]: info: Creating data directory Mar 24 23:53:37 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:37.154Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:37 musicvolumio volumio[3002]: info: Creating Start Script Mar 24 23:53:37 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:37.163Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:37 musicvolumio systemd[1]: Reloading. Mar 24 23:53:38 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:38 musicvolumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:38 musicvolumio sudo[3798]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:38 musicvolumio volumio[3002]: Plugin install end detected on script Mar 24 23:53:38 musicvolumio volumio[3002]: info: Install script completed Mar 24 23:53:38 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:38.148Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:38 musicvolumio volumio[3002]: info: Adding reference to registry Mar 24 23:53:38 musicvolumio volumio5-onboarding[1891]: time=2026-03-24T22:53:38.157Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 24 23:53:38 musicvolumio volumio[3002]: info: Done installing plugin. Mar 24 23:53:38 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:53:38 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 23:53:38 musicvolumio volumio[3002]: info: Folder /tmp/plugins removed Mar 24 23:53:38 musicvolumio volumio[3002]: info: Folder /tmp/downloaded_plugin.zip removed Mar 24 23:53:38 musicvolumio volumio[3002]: info: Folder /data/temp removed Mar 24 23:53:38 musicvolumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Mar 24 23:53:38 musicvolumio systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Mar 24 23:53:38 musicvolumio systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Mar 24 23:53:39 musicvolumio volumio[3002]: info: Enabling plugin spop Mar 24 23:53:39 musicvolumio volumio[3002]: info: Loading plugin "spop"... Mar 24 23:53:40 musicvolumio volumio[3002]: info: PLUGIN START: spop Mar 24 23:53:40 musicvolumio volumio[3002]: info: Creating Spotify config file Mar 24 23:53:40 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 23:53:40 musicvolumio volumio[3002]: info: Done. Mar 24 23:53:40 musicvolumio volumio[3002]: info: Spotify config file written Mar 24 23:53:40 musicvolumio volumio[3002]: info: No need to fix Spotify hosts Mar 24 23:53:40 musicvolumio sudo[3928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 23:53:40 musicvolumio sudo[3928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:40 musicvolumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:40 musicvolumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 23:53:40 musicvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:53:40 musicvolumio go-librespot[3930]: go-librespot daemon starting... Mar 24 23:53:40 musicvolumio sudo[3928]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=info msg="running go-librespot 0.7.1" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=debug msg="no app state found" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=debug msg="stored credentials not found" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=info msg="generated new device id: 632439faf027bc8bb6b9693ed1ce5a2bcb0ac208" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=info msg="zeroconf server listening on port 38857" Mar 24 23:53:40 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:40+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 24 23:53:43 musicvolumio volumio[3002]: info: go-librespot daemon successfully initialized Mar 24 23:53:46 musicvolumio volumio[3002]: info: Initializing connection to go-librespot Websocket Mar 24 23:53:46 musicvolumio go-librespot[3931]: time="2026-03-24T23:53:46+01:00" level=debug msg="new websocket client" Mar 24 23:53:46 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket established Mar 24 23:53:47 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:53:47 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 23:53:49 musicvolumio volumio[3002]: info: Getting Spotify volume Mar 24 23:53:49 musicvolumio volumio[3002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:53:49 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:49 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:49 musicvolumio volumio[3002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 24 23:53:49 musicvolumio volumio[3002]: SPOTIFY: SPOTIFY VOLUME undefined Mar 24 23:53:49 musicvolumio volumio[3002]: SPOTIFY: VOLUMIO VOLUME 86 Mar 24 23:53:49 musicvolumio volumio[3002]: info: Aligning Spotify Volume to Volumio Volume Mar 24 23:53:49 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:49 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:49 musicvolumio volumio[3002]: info: Setting Spotify Volume from Volumio: 86 Mar 24 23:53:50 musicvolumio volumio[3002]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 24 23:53:51 musicvolumio volumio[3002]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Mar 24 23:53:51 musicvolumio volumio[3002]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 23:53:56 musicvolumio volumio[3002]: info: Received OAUTH Data Mar 24 23:53:56 musicvolumio volumio[3002]: info: Executing Spotify Oauth Login Mar 24 23:53:56 musicvolumio volumio[3002]: info: Saving Spotify Refresh Token Mar 24 23:53:56 musicvolumio sudo[3957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:53:56 musicvolumio sudo[3957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:56 musicvolumio sudo[3957]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:56 musicvolumio sudo[3959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:53:56 musicvolumio sudo[3959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:56 musicvolumio sudo[3959]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:56 musicvolumio volumio[3002]: verbose: New Socket.io Connection to 192.168.0.75 from 192.168.0.214 UA: Mozilla/5.0 (Linux; Android 16; 25010PN30G Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.159 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:56 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:53:56 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:56 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:56 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:56 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:56 musicvolumio volumio[3002]: info: Listing playlists Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 24 23:53:56 musicvolumio volumio[3002]: info: New Spotify access tokenBQBCNHxNzv... Mar 24 23:53:56 musicvolumio volumio[3002]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:53:56 musicvolumio volumio[3002]: SPOTIFY: User informations: {"country":"IT","display_name":"Lello Orlando","email":"lellowildnatura@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31efgww3ceiax6csbqiy47irv7va"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31efgww3ceiax6csbqiy47irv7va","id":"31efgww3ceiax6csbqiy47irv7va","images":[],"product":"premium","type":"user","uri":"spotify:user:31efgww3ceiax6csbqiy47irv7va"} Mar 24 23:53:56 musicvolumio volumio[3002]: info: Creating Spotify config file Mar 24 23:53:56 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 23:53:56 musicvolumio volumio[3002]: info: Spotify config file written Mar 24 23:53:56 musicvolumio sudo[3965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 23:53:56 musicvolumio sudo[3965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:53:56 musicvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 23:53:56 musicvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 23:53:56 musicvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:53:56 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket closed Mar 24 23:53:56 musicvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:53:57 musicvolumio go-librespot[3967]: go-librespot daemon starting... Mar 24 23:53:57 musicvolumio sudo[3965]: pam_unix(sudo:session): session closed for user root Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="running go-librespot 0.7.1" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="app state loaded" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="stored credentials not found" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 23:53:57 musicvolumio volumio[3002]: info: New Spotify access tokenBQDT-PBN7V... Mar 24 23:53:57 musicvolumio volumio[3002]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="zeroconf server listening on port 34811" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 24 23:53:57 musicvolumio volumio[3002]: SPOTIFY: User informations: {"country":"IT","display_name":"Lello Orlando","email":"lellowildnatura@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31efgww3ceiax6csbqiy47irv7va"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31efgww3ceiax6csbqiy47irv7va","id":"31efgww3ceiax6csbqiy47irv7va","images":[],"product":"premium","type":"user","uri":"spotify:user:31efgww3ceiax6csbqiy47irv7va"} Mar 24 23:53:57 musicvolumio volumio[3002]: info: Spotify Successfully logged in Mar 24 23:53:57 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 23:53:57 musicvolumio volumio[3002]: info: [1774392837298] CoreMusicLibrary::Adding element Spotify Mar 24 23:53:57 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:53:57 musicvolumio volumio[3002]: Cannot find translation for source Spotify Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="obtained new client token: AAD/ncJZcuYJpGu8M/H6tLYVJ0GXlPJsgyjb8LDv9RbQBmgfXxsYiVMQYTO6Q1ns2kgYI270uMyJsoluQ0slLcSw9nwjckUdMf89vz8bDLWSgshZI0NBq9R++LK8zA/WVkziXmHANhX/P1/qrCd7wA2sj3qkGuYfeGEq2R6iCMYtFqZY+Kw7wyf7q+i01XdRjpibUzeY4QblODOIpU+bqOjfgOxd3ocp2A3T5h4UTRMCHJdRj8ZeUyM=" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="completed keyexchange" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="completed challenge" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="authenticated AP" username="31************************va" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=info msg="authenticated Login5" username="31************************va" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="stored credentials" username="31************************va" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="initializing zeroconf session" username="31************************va" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="dealer connection opened" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=trace msg="starting accesspoint recv loop" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=trace msg="starting dealer recv loop" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=trace msg="received accesspoint ping" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="received connection id: Y2NmNTJlYzgtZTll...Q0EyOTkwNTBCRQ==" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=trace msg="received accesspoint pong ack" Mar 24 23:53:57 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:57+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:53:58 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:58 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:58 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:58 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:59 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:53:59 musicvolumio volumio[3002]: info: Received Get System Info Mar 24 23:53:59 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:53:59 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:53:59 musicvolumio volumio[3002]: info: Discovery: Getting this device information Mar 24 23:53:59 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:53:59 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:53:59 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:53:59 musicvolumio volumio[3002]: info: Initializing connection to go-librespot Websocket Mar 24 23:53:59 musicvolumio go-librespot[3968]: time="2026-03-24T23:53:59+01:00" level=debug msg="new websocket client" Mar 24 23:53:59 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket established Mar 24 23:54:00 musicvolumio volumio[3002]: info: go-librespot daemon successfully initialized Mar 24 23:54:02 musicvolumio volumio[3002]: info: Getting Spotify volume Mar 24 23:54:02 musicvolumio volumio[3002]: info: Spotify volume: 100 Mar 24 23:54:02 musicvolumio volumio[3002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 24 23:54:02 musicvolumio volumio[3002]: info: CoreCommandRouter::volumioGetState Mar 24 23:54:02 musicvolumio volumio[3002]: info: CorePlayQueue::getTrack 0 Mar 24 23:54:02 musicvolumio volumio[3002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Mar 24 23:54:02 musicvolumio volumio[3002]: SPOTIFY: SPOTIFY VOLUME 100 Mar 24 23:54:02 musicvolumio volumio[3002]: SPOTIFY: VOLUMIO VOLUME 86 Mar 24 23:54:02 musicvolumio volumio[3002]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 23:54:02 musicvolumio volumio[3002]: info: Setting Spotify Volume from Volumio: 86 Mar 24 23:54:03 musicvolumio volumio[3002]: info: Initializing connection to go-librespot Websocket Mar 24 23:54:03 musicvolumio go-librespot[3968]: time="2026-03-24T23:54:03+01:00" level=debug msg="new websocket client" Mar 24 23:54:03 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket established Mar 24 23:54:04 musicvolumio volumio[3002]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Mar 24 23:54:04 musicvolumio volumio[3002]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 23:54:04 musicvolumio go-librespot[3968]: time="2026-03-24T23:54:04+01:00" level=debug msg="update volume requested to 56360/65535" Mar 24 23:54:04 musicvolumio go-librespot[3968]: time="2026-03-24T23:54:04+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 24 23:54:04 musicvolumio go-librespot[3968]: time="2026-03-24T23:54:04+01:00" level=trace msg="emitting websocket event: volume" Mar 24 23:54:04 musicvolumio volumio[3002]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Mar 24 23:54:04 musicvolumio volumio[3002]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Mar 24 23:54:04 musicvolumio volumio[3002]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Mar 24 23:54:04 musicvolumio volumio[3002]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Mar 24 23:54:05 musicvolumio volumio[3002]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 24 23:54:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 24 23:54:05 musicvolumio volumio[3002]: info: Creating Spotify config file Mar 24 23:54:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 23:54:05 musicvolumio volumio[3002]: info: Spotify config file written Mar 24 23:54:05 musicvolumio sudo[3993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 23:54:05 musicvolumio sudo[3993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:54:05 musicvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 23:54:05 musicvolumio systemd[1]: go-librespot-daemon.service: Killing process 3973 (go-librespot) with signal SIGKILL. Mar 24 23:54:05 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket closed Mar 24 23:54:05 musicvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 23:54:05 musicvolumio volumio[3002]: info: Connection to go-librespot Websocket closed Mar 24 23:54:05 musicvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:54:05 musicvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:54:05 musicvolumio go-librespot[3995]: go-librespot daemon starting... Mar 24 23:54:05 musicvolumio sudo[3993]: pam_unix(sudo:session): session closed for user root Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=info msg="running go-librespot 0.7.1" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="app state loaded" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=info msg="zeroconf server listening on port 36335" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="obtained new client token: AADdQUcX1YfrCWyEGF+qWfpXrw7bB7eyap3iGkgbUYN9aw03VbMXtFbDkS9IlJlXisGqENRTAWHnd5oelQG0DJEG51CdD7ViL/kRPr0iY4P92n2huYYe0t3EDQxcojD9vYu7XOaVYBkQGahgF5IkedAAurm8AtaGPtL0U04prHPOSzFrQgcBDCEb/NFs2LafHeTWn1+NpuZCrdvJxhqgc5BHH6VW6OZ3rjRWu9MIrqn1MF8a1m7B5DA=" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 23:54:05 musicvolumio volumio[3002]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 24 23:54:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 24 23:54:05 musicvolumio volumio[3002]: info: Creating Spotify config file Mar 24 23:54:05 musicvolumio volumio[3002]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 23:54:05 musicvolumio volumio[3002]: info: Spotify config file written Mar 24 23:54:05 musicvolumio sudo[4007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 23:54:05 musicvolumio sudo[4007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="completed keyexchange" Mar 24 23:54:05 musicvolumio go-librespot[3997]: time="2026-03-24T23:54:05+01:00" level=debug msg="completed challenge" Mar 24 23:54:05 musicvolumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 23:54:05 musicvolumio systemd[1]: go-librespot-daemon.service: Killing process 4003 (go-librespot) with signal SIGKILL. Mar 24 23:54:05 musicvolumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 23:54:05 musicvolumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:54:05 musicvolumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 23:54:05 musicvolumio go-librespot[4009]: go-librespot daemon starting... Mar 24 23:54:05 musicvolumio sudo[4007]: pam_unix(sudo:session): session closed for user root Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=info msg="running go-librespot 0.7.1" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="app state loaded" Mar 24 23:54:06 musicvolumio volumio[3002]: info: Getting Spotify volume Mar 24 23:54:06 musicvolumio volumio[3002]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 23:54:06 musicvolumio volumio[3002]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 23:54:06 musicvolumio volumio[3002]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 23:54:06 musicvolumio volumio[3002]: errno: -111, Mar 24 23:54:06 musicvolumio volumio[3002]: code: 'ECONNREFUSED', Mar 24 23:54:06 musicvolumio volumio[3002]: syscall: 'connect', Mar 24 23:54:06 musicvolumio volumio[3002]: address: '127.0.0.1', Mar 24 23:54:06 musicvolumio volumio[3002]: port: 9879, Mar 24 23:54:06 musicvolumio volumio[3002]: response: undefined Mar 24 23:54:06 musicvolumio volumio[3002]: } Mar 24 23:54:06 musicvolumio volumio[3002]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=info msg="zeroconf server listening on port 45293" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="obtained new client token: AAAtuVm5LizkImuipSwCKJQ+tsA7mwJLrrKyPiCGNJd8Yo5XOW1KUgU0X87F8NNl88+tuOOjd+yWnFXtuKjkiatjeVGh3WhRAq9VbS/yeqewlG5bUuxk3joTQum/wQzoy505cPcKxcbYsEmXTm8EoYhR13PtDD20+Fc/RO8u+XRcT/ZDmoPUNwQH1XmX4X1fZSdbU8tR5+Ft8tIWrf9lQCNTlIj0/KkC+78Y/g1ABQvJChQu3jeEqGE=" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 23:54:06 musicvolumio sudo[4033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 23:53' Mar 24 23:54:06 musicvolumio sudo[4033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="completed keyexchange" Mar 24 23:54:06 musicvolumio go-librespot[4010]: time="2026-03-24T23:54:06+01:00" level=debug msg="completed challenge" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"