Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Received OAUTH Data Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Executing Spotify Oauth Login Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Saving Spotify Refresh Token Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: BQAA985SYAOk1W4qp53vlktRPicsSf7ks3fH_p2xdhnsQmxV3bf_H-k_7unKU2vHTfSZhyFnjb0l8V_ZIhUjiNO7R00trqrKxm5ief_d36ks_D88lgd1KZbU2VO133rFEou1QsoiRd7NNgoj27IN3PfA5F-sr0ydOEdrliVtc-FUAlzHFlTRLD8qQ7xd7_AQ2HQFh-YHVNN6n1MelpE0HRhtJd7tM_b6GKALdamJu0JZesdaaczqBWK6A4IpfjCj2INAlkFkrAqvOOn192lQDthgmh16_SuIfPNfBFb9bHSKeUUF1TtzEWM6wNBPIt_5LKrxv5A9-9ornkSMRuEy7vTk62iS5deTr_JSDP9ATdmL3-x-Co7tyTWhYS1IVwA6OMa4cEdFsR8TOyg Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: New Spotify access token = BQAA985SYAOk1W4qp53vlktRPicsSf7ks3fH_p2xdhnsQmxV3bf_H-k_7unKU2vHTfSZhyFnjb0l8V_ZIhUjiNO7R00trqrKxm5ief_d36ks_D88lgd1KZbU2VO133rFEou1QsoiRd7NNgoj27IN3PfA5F-sr0ydOEdrliVtc-FUAlzHFlTRLD8qQ7xd7_AQ2HQFh-YHVNN6n1MelpE0HRhtJd7tM_b6GKALdamJu0JZesdaaczqBWK6A4IpfjCj2INAlkFkrAqvOOn192lQDthgmh16_SuIfPNfBFb9bHSKeUUF1TtzEWM6wNBPIt_5LKrxv5A9-9ornkSMRuEy7vTk62iS5deTr_JSDP9ATdmL3-x-Co7tyTWhYS1IVwA6OMa4cEdFsR8TOyg Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: User informations: {"country":"SK","display_name":"Ján","email":"jan.ferianc@icloud.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zwgq6nckzwsshtrg7jrmvsyqim"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31zwgq6nckzwsshtrg7jrmvsyqim","id":"31zwgq6nckzwsshtrg7jrmvsyqim","images":[],"product":"premium","type":"user","uri":"spotify:user:31zwgq6nckzwsshtrg7jrmvsyqim"} Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Creating Spotify config file Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Spotify config file written Dec 30 16:31:58 volumio-pi5 sudo[22164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 16:31:58 volumio-pi5 sudo[22164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:31:58 volumio-pi5 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 16:31:58 volumio-pi5 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 16:31:58 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Connection to go-librespot Websocket closed Dec 30 16:31:58 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:31:58 volumio-pi5 go-librespot[22166]: go-librespot daemon starting... Dec 30 16:31:58 volumio-pi5 sudo[22164]: pam_unix(sudo:session): session closed for user root Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=debug msg="app state loaded" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=debug msg="stored credentials not found" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:31:58 volumio-pi5 sudo[22175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 16:31:58 volumio-pi5 sudo[22175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:31:58 volumio-pi5 sudo[22175]: pam_unix(sudo:session): session closed for user root Dec 30 16:31:58 volumio-pi5 sudo[22177]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 16:31:58 volumio-pi5 sudo[22177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:31:58 volumio-pi5 sudo[22177]: pam_unix(sudo:session): session closed for user root Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: BQCTCWxg6PM3pIc7kL3lkDa1KQoQhIcIaLJVQw0hDXSaZbA_Dbsi63BTx5Ia9Xb-zw19Oj-bR3WwaXjG6FoJBEhwwWgZ9YeT1eDHyzzisQhtXVU17G6qxHxrWSr5b6TytfzP8-y-U3NmLzECUyEbMO6y9ZJ5svlIIhlNBSLHBOjdZ8FWoefdbSl5WMiNipVUJtIRLVJocIGqaymkYSgu7_h2DVq7PluxXwUZjilP-uIh0nUzTV7wQIKTmmL3FRtT7erqwXfKq53JOodEwRreAiI5avhmKfPmcckuSxFwrEdx_FwcN6Tk2hqQYWr69qWo4_45qAJxBJZE9pPM6OuNVfxNgVFx_McoVsenmxCSvs8eW7HiTTDAL0bn_ev3YkGQi81frsBCKHWcjg8 Dec 30 16:31:58 volumio-pi5 volumio[1393]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: New Spotify access token = BQCTCWxg6PM3pIc7kL3lkDa1KQoQhIcIaLJVQw0hDXSaZbA_Dbsi63BTx5Ia9Xb-zw19Oj-bR3WwaXjG6FoJBEhwwWgZ9YeT1eDHyzzisQhtXVU17G6qxHxrWSr5b6TytfzP8-y-U3NmLzECUyEbMO6y9ZJ5svlIIhlNBSLHBOjdZ8FWoefdbSl5WMiNipVUJtIRLVJocIGqaymkYSgu7_h2DVq7PluxXwUZjilP-uIh0nUzTV7wQIKTmmL3FRtT7erqwXfKq53JOodEwRreAiI5avhmKfPmcckuSxFwrEdx_FwcN6Tk2hqQYWr69qWo4_45qAJxBJZE9pPM6OuNVfxNgVFx_McoVsenmxCSvs8eW7HiTTDAL0bn_ev3YkGQi81frsBCKHWcjg8 Dec 30 16:31:58 volumio-pi5 volumio[1393]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 16:31:58 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:58+01:00" level=info msg="zeroconf server listening on port 37059" Dec 30 16:31:58 volumio-pi5 volumio[1393]: verbose: New Socket.io Connection to 192.168.1.156 from 192.168.1.242 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 12 Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="obtained new client token: AABA7m0zDmmu3XG84+jlkpLFPP3yaDUSwiF5NnrsiIVkhGIzAH4LP9pAD7L4HAUkEJfXgRVvRs0bq8DdEUeAK6zBPUNZ5ZXySPZ+Hu/hn7WQwNaD8aCjL6I4w+zFlAv2iTUjqsdyeKTjrZI9pYI21ff4RonYev5eKfHQy/arqT2V6u0ECLZV3/1PUN2DCXiNFY9PwGMg/PrqEWfjt3wNNgschAg+8OP/HIpexR78fHG8op4iSYe9ryQ=" Dec 30 16:31:59 volumio-pi5 volumio[1393]: SPOTIFY: User informations: {"country":"SK","display_name":"Ján","email":"jan.ferianc@icloud.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zwgq6nckzwsshtrg7jrmvsyqim"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31zwgq6nckzwsshtrg7jrmvsyqim","id":"31zwgq6nckzwsshtrg7jrmvsyqim","images":[],"product":"premium","type":"user","uri":"spotify:user:31zwgq6nckzwsshtrg7jrmvsyqim"} Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: Spotify Successfully logged in Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: [1767108719060] CoreMusicLibrary::Adding element Spotify Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:31:59 volumio-pi5 volumio[1393]: Cannot find translation for source Loopback Dec 30 16:31:59 volumio-pi5 volumio[1393]: Cannot find translation for source Spotify Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="completed keyexchange" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="completed challenge" Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=info msg="authenticated AP" username="31************************im" Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::volumioGetState Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CorePlayQueue::getTrack 0 Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 30 16:31:59 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=info msg="authenticated Login5" username="31************************im" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="stored credentials" username="31************************im" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="initializing zeroconf session" username="31************************im" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="dealer connection opened" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=trace msg="starting accesspoint recv loop" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=trace msg="starting dealer recv loop" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=trace msg="received accesspoint ping" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="received connection id: ZjU3YjMyYTctMDdl...RDlGMUExNTAzOA==" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=trace msg="received accesspoint pong ack" Dec 30 16:31:59 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:31:59+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: Received Get System Info Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: Discovery: Getting this device information Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:00 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: Initializing connection to go-librespot Websocket Dec 30 16:32:01 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:32:01+01:00" level=debug msg="new websocket client" Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: Connection to go-librespot Websocket established Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: go-librespot daemon successfully initialized Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: Received Get System Info Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: Discovery: Getting this device information Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:01 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: Getting Spotify volume Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: Spotify volume: 100 Dec 30 16:32:04 volumio-pi5 volumio[1393]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:04 volumio-pi5 volumio[1393]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:04 volumio-pi5 volumio[1393]: SPOTIFY: SPOTIFY VOLUME 100 Dec 30 16:32:04 volumio-pi5 volumio[1393]: SPOTIFY: VOLUMIO VOLUME 5 Dec 30 16:32:04 volumio-pi5 volumio[1393]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: Setting Spotify Volume from Volumio: 5 Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: Initializing connection to go-librespot Websocket Dec 30 16:32:04 volumio-pi5 go-librespot[22167]: time="2025-12-30T16:32:04+01:00" level=debug msg="new websocket client" Dec 30 16:32:04 volumio-pi5 volumio[1393]: info: Connection to go-librespot Websocket established Dec 30 16:32:06 volumio-pi5 volumio[1393]: SPOTIFY: SETTING SPOTIFY VOLUME 5 Dec 30 16:32:06 volumio-pi5 volumio[1393]: info: Sending Spotify command with payload to local API: /player/volume Dec 30 16:32:06 volumio-pi5 volumio[1393]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: Creating Spotify config file Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: Spotify config file written Dec 30 16:32:07 volumio-pi5 sudo[22198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 16:32:07 volumio-pi5 sudo[22198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:07 volumio-pi5 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 16:32:07 volumio-pi5 systemd[1]: go-librespot-daemon.service: Killing process 22180 (go-librespot) with signal SIGKILL. Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: Connection to go-librespot Websocket closed Dec 30 16:32:07 volumio-pi5 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 16:32:07 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: Connection to go-librespot Websocket closed Dec 30 16:32:07 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:07 volumio-pi5 go-librespot[22200]: go-librespot daemon starting... Dec 30 16:32:07 volumio-pi5 volumio[1393]: info: Getting Spotify volume Dec 30 16:32:07 volumio-pi5 sudo[22198]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:07 volumio-pi5 volumio[1393]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 16:32:07 volumio-pi5 volumio[1393]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 16:32:07 volumio-pi5 volumio[1393]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 30 16:32:07 volumio-pi5 volumio[1393]: errno: -111, Dec 30 16:32:07 volumio-pi5 volumio[1393]: code: 'ECONNREFUSED', Dec 30 16:32:07 volumio-pi5 volumio[1393]: syscall: 'connect', Dec 30 16:32:07 volumio-pi5 volumio[1393]: address: '127.0.0.1', Dec 30 16:32:07 volumio-pi5 volumio[1393]: port: 9879, Dec 30 16:32:07 volumio-pi5 volumio[1393]: response: undefined Dec 30 16:32:07 volumio-pi5 volumio[1393]: } Dec 30 16:32:07 volumio-pi5 volumio[1393]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=debug msg="app state loaded" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 16:32:07 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:07+01:00" level=info msg="zeroconf server listening on port 39713" Dec 30 16:32:08 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:08+01:00" level=debug msg="obtained new client token: AADKHK5H9VB57TG/cFm+z3ajR+3SQB2eLCKoDlUnl5Z2rGVFhmB393ClgPNkAhZ9O3DIEZ8COEiL4nwsu4tqGnE9gugXV7MS4g1AAbSoSh0dbsOokJE3zfWmZ15+mz1WfVqTi/bX94qkR1sEgdqANINmmpRsluTQkPMROxRf4P4XzbJMRZPkYd7N8aRs9LMGOlDdbNVFz/YKgr2DwwO9iYp4l2gHsEysqFelv/+g9yfA4zK+jm6y7n4=" Dec 30 16:32:08 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:08+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:32:08 volumio-pi5 go-librespot[22201]: time="2025-12-30T16:32:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 30 16:32:08 volumio-pi5 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 16:32:08 volumio-pi5 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 16:32:08 volumio-pi5 sudo[22223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 16:31' Dec 30 16:32:08 volumio-pi5 sudo[22223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:08 volumio-pi5 sudo[22223]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:08 volumio-pi5 volumio-remote-updater[1037]: [2025-12-30 16:32:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 30 16:32:08 volumio-pi5 volumio-remote-updater[1037]: [2025-12-30 16:32:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 30 16:32:08 volumio-pi5 qobuz-connect[2267]: 20251230 16:32:08.310 [2267.2267] INFO SampleApp: Socket closed Dec 30 16:32:08 volumio-pi5 vtcs[2347]: [2025-12-30 16:32:08.311] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 30 16:32:08 volumio-pi5 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 30 16:32:08 volumio-pi5 systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 30 16:32:08 volumio-pi5 systemd[1]: volumio.service: Consumed 1min 34.845s CPU time. Dec 30 16:32:08 volumio-pi5 systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 16:32:08 volumio-pi5 systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 16:32:08 volumio-pi5 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Dec 30 16:32:08 volumio-pi5 systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 30 16:32:08 volumio-pi5 systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 30 16:32:08 volumio-pi5 systemd[1]: volumio.service: Consumed 1min 34.845s CPU time. Dec 30 16:32:08 volumio-pi5 systemd[1]: Started volumio.service - Volumio Backend Module. Dec 30 16:32:08 volumio-pi5 systemd[1]: dynamicswap.service: Deactivated successfully. Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ----- Volumio3 ---- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ----- System startup ---- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: MYVOLUMIO Environment detected Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Plugin folders cleanup Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning into folder /volumio/app/plugins/ Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category audio_interface Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category miscellanea Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category music_service Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category plugins.json Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category system_controller Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category user_interface Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning into folder /data/plugins/ Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category music_service Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Scanning category user_interface Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Plugin folders cleanup completed Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ----- Core plugins startup ---- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugins from folder /volumio/app/plugins/ Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Adding plugin upnp to MyMusic Plugins Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugins from folder /data/plugins/ Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "system"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "appearance"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "network"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Refreshing Cached IP Addresses Dec 30 16:32:09 volumio-pi5 sudo[22290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 16:32:09 volumio-pi5 sudo[22290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:09 volumio-pi5 sudo[22292]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 16:32:09 volumio-pi5 sudo[22292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:09 volumio-pi5 sudo[22290]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:09 volumio-pi5 sudo[22292]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "services"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "alsa_controller"... Dec 30 16:32:09 volumio-pi5 sudo[22301]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 30 16:32:09 volumio-pi5 sudo[22301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "wizard"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "networkfs"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Starting Udev Watcher for removable devices Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Ignoring mount for partition: boot Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Ignoring mount for partition: volumio Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Ignoring mount for partition: volumio_data Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "volumio_command_line_client"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "upnp"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: [1767108729849] Starting Upmpd Daemon Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "my_music"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "mpd"... Dec 30 16:32:09 volumio-pi5 volumio[22258]: info: Loading plugin "upnp_browser"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Starting UPNP Browser Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "alarm-clock"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "airplay_emulation"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "last_100"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "webradio"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "i2s_dacs"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "volumiodiscovery"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** For more information see Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 16:32:10 volumio-pi5 volumio[22258]: *** WARNING *** For more information see Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** For more information see Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 30 16:32:10 volumio-pi5 node[22258]: *** WARNING *** For more information see Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Discovery: Started advertising with name: Volumio PI5 Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "spop"... Dec 30 16:32:10 volumio-pi5 volumio[22258]: info: Loading plugin "now_playing"... Dec 30 16:32:11 volumio-pi5 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 30 16:32:11 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:11 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:11 volumio-pi5 go-librespot[22325]: go-librespot daemon starting... Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="app state loaded" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "outputs"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "albumart"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Plugin example_plugin is not enabled Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "inputs"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "updater_comm"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Plugin mpdemulation is not enabled Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "rest_api"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "websocket"... Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Starting Socket.io Server version 1.7.4 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "peppymeterbasic"... Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=info msg="zeroconf server listening on port 35805" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="obtained new client token: AABVUtpIxtrOE8oKjCY1c8u3kJF/2xtIVt8eiGA5reoKJOoAvt4ueG61/qWSyTWL6HID97hn5kKJKZCPysl/9k+j0Hk972/cJM7DWZPssI12jqFp+8X8eWEKKEHtRGjsgZK6bAZR2Z9UwycabDJU6TL8+CpbyuoUGFQZTQErHnsLZcN8sVvbAuZXmR8OPmssvqLECaI+bk1MK8dcLZRMTxLSamiGPEqgCiM3bnJmk7/C+1Y2+bbpzTWDkw==" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading plugin "touch_display"... Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="completed keyexchange" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="completed challenge" Dec 30 16:32:11 volumio-pi5 volumio[22334]: Forking 3 albumart workers Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Applying required configuration parameters for plugin touch_display Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=info msg="authenticated AP" username="31************************im" Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Loading i18n strings for locale sk Dec 30 16:32:11 volumio-pi5 volumio[22258]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Dec 30 16:32:11 volumio-pi5 volumio[22258]: Updating browse sources language Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::initPlayerControls Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: Express server listening on port 3000 Dec 30 16:32:11 volumio-pi5 volumio[22258]: [Metrics] WebUI: 2s 433.87ms Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=info msg="authenticated Login5" username="31************************im" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="initializing zeroconf session" username="31************************im" Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::resetVolumioState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::getcurrentVolume Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Volumio Network Manager: Network status updated: 1 Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156:3000 from 192.168.1.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::updateTrackBlock Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrackBlock Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioRetrievevolume Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="dealer connection opened" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=trace msg="starting accesspoint recv loop" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=trace msg="starting dealer recv loop" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=trace msg="received accesspoint ping" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="received connection id: MWZhZmFjMWUtOWIx...NTIwMEY5MDZBNQ==" Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=trace msg="received accesspoint pong ack" Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156:3000 from 192.168.1.242 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 2 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Reloading queue from file Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156:3000 from 192.168.1.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::setRepeat true single undefined Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::setRandom undefined Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Setting Device type: Raspberry PI Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04170 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 30 16:32:11 volumio-pi5 go-librespot[22326]: time="2025-12-30T16:32:11+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Completed loading Core Plugins Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Preparing to generate the ALSA configuration file Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Reading ALSA contributions from plugins. Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156 from 192.168.1.242 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156:3000 from 192.168.1.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Listing playlists Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::getQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetVisibleSources Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Listing playlists Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreStateMachine::getQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getQueue Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetVisibleSources Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22346]: Starting albumart workers Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: adding d48bc97c-8078-4e5e-a678-70942e8ffd4f Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: Found device Volumio PI5 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: this is already registered, d48bc97c-8078-4e5e-a678-70942e8ffd4f Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: Found device Volumio PI5 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: adding cb3017d0-dc69-4fff-af24-f40e6ed5c557 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: Found device Volumio obývačka Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: Connecting to remote: 192.168.1.170 Dec 30 16:32:11 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156:3000 from 192.168.1.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Discovery: Getting this device information Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 16:32:11 volumio-pi5 volumio[22344]: Starting albumart workers Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Asound.conf file written Dec 30 16:32:11 volumio-pi5 sudo[22402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 30 16:32:11 volumio-pi5 sudo[22402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:11 volumio-pi5 sudo[22402]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:11 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 30 16:32:11 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 30 16:32:11 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 30 16:32:11 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Output device has changed, restarting MPD Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: Output device has changed, restarting Shairport Sync Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:11 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: ___________ START PLUGINS ___________ Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: ControllerMpd::onStart: Initializing MPD Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Creating MPD Configuration file Dec 30 16:32:12 volumio-pi5 sudo[22409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 16:32:12 volumio-pi5 sudo[22409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 16:32:12 volumio-pi5 sudo[22412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: [1767108732021] CoreMusicLibrary::Adding element Mediálne servery Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:12 volumio-pi5 sudo[22409]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: UPNP Browser: Client initialized successfully Dec 30 16:32:12 volumio-pi5 volumio[22345]: Starting albumart workers Dec 30 16:32:12 volumio-pi5 sudo[22417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 16:32:12 volumio-pi5 sudo[22417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 16:32:12 volumio-pi5 sudo[22419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 sudo[22417]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 systemd[1]: mpd.service: Deactivated successfully. Dec 30 16:32:12 volumio-pi5 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 16:32:12 volumio-pi5 systemd[1]: mpd.socket: Deactivated successfully. Dec 30 16:32:12 volumio-pi5 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 16:32:12 volumio-pi5 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: [1767108732088] CoreMusicLibrary::Adding element Last_100 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: [1767108732091] CoreMusicLibrary::Adding element Webradio Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Initializing BBC Radios Dec 30 16:32:12 volumio-pi5 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 16:32:12 volumio-pi5 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 16:32:12 volumio-pi5 systemd[1]: mpd.service: Deactivated successfully. Dec 30 16:32:12 volumio-pi5 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 16:32:12 volumio-pi5 systemd[1]: mpd.socket: Deactivated successfully. Dec 30 16:32:12 volumio-pi5 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 16:32:12 volumio-pi5 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 16:32:12 volumio-pi5 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 16:32:12 volumio-pi5 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Creating Spotify config file Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 sudo[22449]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 16:32:12 volumio-pi5 sudo[22449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 16:32:12 volumio-pi5 sudo[22449]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: [now-playing] ConfigUpdater: config is up to date. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 30 16:32:12 volumio-pi5 sudo[22463]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Loading i18n strings for locale sk Dec 30 16:32:12 volumio-pi5 sudo[22463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Volumio Calling Home Dec 30 16:32:12 volumio-pi5 sudo[22463]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Preparing to generate the ALSA configuration file Dec 30 16:32:12 volumio-pi5 sudo[22475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Dec 30 16:32:12 volumio-pi5 sudo[22475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Dec 30 16:32:12 volumio-pi5 sudo[22478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 30 16:32:12 volumio-pi5 sudo[22480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 systemd[1]: Reloading. Dec 30 16:32:12 volumio-pi5 sudo[22301]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: [now-playing] App is listening on port 4004. Dec 30 16:32:12 volumio-pi5 volumio[22258]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 192.168.1.156 from 192.168.1.242 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Reading ALSA contributions from plugins. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: touch_display: No backlight interface detected. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: snd_dummy loaded Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: MPD Permissions set Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: MPD Permissions set Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Volumio called home Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Spotify config file written Dec 30 16:32:12 volumio-pi5 sudo[22502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 30 16:32:12 volumio-pi5 sudo[22502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: No need to fix Spotify hosts Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:12 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Dec 30 16:32:12 volumio-pi5 sudo[22515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Dec 30 16:32:12 volumio-pi5 sudo[22515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22515]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 sudo[22517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Dec 30 16:32:12 volumio-pi5 sudo[22517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:12 volumio-pi5 sudo[22517]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:12 volumio-pi5 volumio[22258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:32:12 volumio-pi5 volumio[22258]: SPOTIFY: BQB_bPXARKPRI_hjPOIcafk8mgPRxa74FljAXDelDAsI7ZhpHoDOaQ2wLzaqvd5sncpcWwA2tPBRkYah-O6_3dd2Ius2nhACP3EH_2qyelxRVqtAtKVIfkYpnoPMvMkMOeqXRtxUFm7DaA7uuQ7XggUop8ZWfGg3iD_N34GR4MSYivktQfqo4ivPd8GNQmzC20aLsmyubSl4J_dGHvrkEM4_2jaIvnTAN5bWxikCPiYwRIHA-ILSDM83gPUTW337Y_DdySKO-laoH8h5WguaLDsR5XT8DZVwZFsEB6D5PeqxeQcAgG095P7ly6cUvRZmPaX3LlqL4ZAnMryGXp8uGKyIUydhICRNikjD31eoAIiIj9SuS2sygIWmzZf9uOaBVwo-GO0igfSoTl4 Dec 30 16:32:12 volumio-pi5 volumio[22258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: New Spotify access token = BQB_bPXARKPRI_hjPOIcafk8mgPRxa74FljAXDelDAsI7ZhpHoDOaQ2wLzaqvd5sncpcWwA2tPBRkYah-O6_3dd2Ius2nhACP3EH_2qyelxRVqtAtKVIfkYpnoPMvMkMOeqXRtxUFm7DaA7uuQ7XggUop8ZWfGg3iD_N34GR4MSYivktQfqo4ivPd8GNQmzC20aLsmyubSl4J_dGHvrkEM4_2jaIvnTAN5bWxikCPiYwRIHA-ILSDM83gPUTW337Y_DdySKO-laoH8h5WguaLDsR5XT8DZVwZFsEB6D5PeqxeQcAgG095P7ly6cUvRZmPaX3LlqL4ZAnMryGXp8uGKyIUydhICRNikjD31eoAIiIj9SuS2sygIWmzZf9uOaBVwo-GO0igfSoTl4 Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 30 16:32:12 volumio-pi5 sudo[22521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 16:32:12 volumio-pi5 sudo[22521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 16:32:12 volumio-pi5 sudo[22525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 16:32:12 volumio-pi5 sudo[22523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Asound.conf file unchanged, so no further update is needed Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Output device has changed, restarting MPD Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Output device has changed, restarting Shairport Sync Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 sudo[22533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 16:32:12 volumio-pi5 sudo[22533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 16:32:12 volumio-pi5 sudo[22530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 16:32:12 volumio-pi5 sudo[22530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:12 volumio-pi5 sudo[22530]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: MPD Permissions set Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:12 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:12 volumio-pi5 sudo[22548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 16:32:12 volumio-pi5 sudo[22548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:13 volumio-pi5 volumio[22258]: SPOTIFY: User informations: {"country":"SK","display_name":"Ján","email":"jan.ferianc@icloud.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31zwgq6nckzwsshtrg7jrmvsyqim"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31zwgq6nckzwsshtrg7jrmvsyqim","id":"31zwgq6nckzwsshtrg7jrmvsyqim","images":[],"product":"premium","type":"user","uri":"spotify:user:31zwgq6nckzwsshtrg7jrmvsyqim"} Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Spotify Successfully logged in Dec 30 16:32:13 volumio-pi5 mpd[22459]: 2025-12-30T16:32:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: [1767108733013] CoreMusicLibrary::Adding element Spotify Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:13 volumio-pi5 volumio[22258]: Cannot find translation for source Spotify Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 sudo[22480]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 16:32:13 volumio-pi5 sudo[22419]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 systemd[1]: Reloading. Dec 30 16:32:13 volumio-pi5 sudo[22412]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: systemctl daemon-reload succeeded. Dec 30 16:32:13 volumio-pi5 sudo[22554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Dec 30 16:32:13 volumio-pi5 sudo[22554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:13 volumio-pi5 volumio[22258]: error: MPD error: The expression evaluated to a falsy value: Dec 30 16:32:13 volumio-pi5 volumio[22258]: assert.ok(self.idling) Dec 30 16:32:13 volumio-pi5 volumio[22258]: error: The expression evaluated to a falsy value: Dec 30 16:32:13 volumio-pi5 volumio[22258]: assert.ok(self.idling) Dec 30 16:32:13 volumio-pi5 volumio[22258]: error: updateQueue error: null Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: MPD running with PID22459 Dec 30 16:32:13 volumio-pi5 volumio[22258]: ,establishing connection Dec 30 16:32:13 volumio-pi5 volumio[22258]: error: updateQueue error: null Dec 30 16:32:13 volumio-pi5 volumio-remote-updater[1037]: [2025-12-30 16:32:13] [connect] Successful connection Dec 30 16:32:13 volumio-pi5 volumio-remote-updater[1037]: [2025-12-30 16:32:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1767108733 101 Dec 30 16:32:13 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 11 Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetVisibleSources Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetQueue Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreStateMachine::getQueue Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CorePlayQueue::getQueue Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Listing playlists Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 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. Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:13 volumio-pi5 sudo[22478]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: systemctl disable getty@tty1.service succeeded. Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 16:32:13 volumio-pi5 sudo[22554]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: Volumio Kiosk started. Dec 30 16:32:13 volumio-pi5 systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 16:32:13 volumio-pi5 systemd[1]: shairport-sync.service: Consumed 27.367s CPU time. Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:13 volumio-pi5 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Completed starting Core Plugins Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: ----- MyVolumio plugins startup ---- Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: ------------------------------------------- Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:13 volumio-pi5 systemd[1]: mpd.service: Deactivated successfully. Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 16:32:13 volumio-pi5 sudo[22475]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: systemctl stop getty@tty1.service succeeded. Dec 30 16:32:13 volumio-pi5 systemd[1]: mpd.socket: Deactivated successfully. Dec 30 16:32:13 volumio-pi5 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 16:32:13 volumio-pi5 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: X display number found: 0 Dec 30 16:32:13 volumio-pi5 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 16:32:13 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:13 volumio-pi5 go-librespot[22578]: go-librespot daemon starting... Dec 30 16:32:13 volumio-pi5 sudo[22502]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 16:32:13 volumio-pi5 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 16:32:13 volumio-pi5 sudo[22521]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 sudo[22548]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 sudo[22523]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 sudo[22525]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Shairport-Sync Started Dec 30 16:32:13 volumio-pi5 volumio[22258]: Error adding Membership: Error: addMembership EINVAL Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Shairport-Sync Started Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Shairport-Sync Started Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: Shairport-Sync Started Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01:00" level=debug msg="app state loaded" Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: X display number found: 0 Dec 30 16:32:13 volumio-pi5 sudo[22580]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 16:32:13 volumio-pi5 sudo[22580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 16:32:13 volumio-pi5 sudo[22580]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01: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]" Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01: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]" Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01: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]" Dec 30 16:32:13 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:13+01:00" level=info msg="zeroconf server listening on port 41493" Dec 30 16:32:13 volumio-pi5 volumio[22258]: info: touch_display: Setting screensaver timeout to 120 seconds. Dec 30 16:32:14 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:14+01:00" level=debug msg="obtained new client token: AADvz2AAvZTYgZIBnz4N/6KbCSf6kFyFJnBAyBbrKiWKUwM3uHgjBA/idu2/shUWuFu08XcUh+9nEoQg3j34tDBIZfhqf9mY4EmrsrNUSGUtmxWDTtcWkH7yv5Zwtzmq10bg5XmTXcyQmluCL+3cETiWS/2VacA0jWEvaIx3O6dhOsPo/w1E24wn+ucZzhif6ZuVIVVLxM+m6hm9+L0xnEfXQ+e9ZtOsFDpCTxRp+nJUzjtl/dfyoD8=" Dec 30 16:32:14 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:14+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:32:14 volumio-pi5 go-librespot[22579]: time="2025-12-30T16:32:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.156:43230->104.199.65.9:4070: read: connection reset by peer" Dec 30 16:32:14 volumio-pi5 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 16:32:14 volumio-pi5 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 16:32:14 volumio-pi5 mpd[22606]: 2025-12-30T16:32:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 16:32:14 volumio-pi5 systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 16:32:14 volumio-pi5 sudo[22533]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:14 volumio-pi5 volumio[22258]: error: updateQueue error: null Dec 30 16:32:14 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:14 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:14 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:14 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 sudo[22614]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 16:32:16 volumio-pi5 sudo[22614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:16 volumio-pi5 sudo[22617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 sudo[22617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:16 volumio-pi5 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 16:32:16 volumio-pi5 systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 16:32:16 volumio-pi5 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:16 volumio-pi5 systemd[1]: mpd_monitor.service: Consumed 5.922s CPU time. Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:16 volumio-pi5 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:16 volumio-pi5 sudo[22614]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:16 volumio-pi5 mpd_monitor.sh[22619]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 16:32:16 volumio-pi5 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 16:32:16 volumio-pi5 systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 16:32:16 volumio-pi5 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Successfully started MPD Monitor Dec 30 16:32:16 volumio-pi5 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:16 volumio-pi5 mpd_monitor.sh[22621]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 16:32:16 volumio-pi5 sudo[22617]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: Successfully started MPD Monitor Dec 30 16:32:16 volumio-pi5 volumio[22258]: info: go-librespot daemon successfully initialized Dec 30 16:32:17 volumio-pi5 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 30 16:32:17 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:17 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:17 volumio-pi5 go-librespot[22625]: go-librespot daemon starting... Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="app state loaded" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=info msg="zeroconf server listening on port 39325" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="obtained new client token: AAAtsLtN9KSoy9pFkBMW1fzFSp4NRGSNMvVZq21Hy8iaRfzQkZtk0J+/1nFQnmQGawvt0VEZIByBAGdf3oNorANG3U6WhtnSOQbFRVndWeZ1BdbrIEVFsZy8AREKSsV19OKIRA5y0tWBbrHuOPXGF4VVYLmfVYqCRURhCqkieswzqwl3yPs0JATMTDG5u82nUPaOv0hq7ohKQRf41UqjWhMtZVAynlcppi7HE20RFbL3Neu6n6Rg+PdUBw==" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:32:17 volumio-pi5 go-librespot[22626]: time="2025-12-30T16:32:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Dec 30 16:32:17 volumio-pi5 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 30 16:32:17 volumio-pi5 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Received Get System Version Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Received Get System Info Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Getting this device information Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:17 volumio-pi5 sudo[22634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 16:32:17 volumio-pi5 sudo[22634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:17 volumio-pi5 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 16:32:17 volumio-pi5 systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 16:32:17 volumio-pi5 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:17 volumio-pi5 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:17 volumio-pi5 sudo[22634]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:17 volumio-pi5 mpd_monitor.sh[22636]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 16:32:17 volumio-pi5 volumio[22258]: info: Successfully started MPD Monitor Dec 30 16:32:18 volumio-pi5 volumio[22258]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:18 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:19 volumio-pi5 volumio[22258]: info: Initializing connection to go-librespot Websocket Dec 30 16:32:19 volumio-pi5 volumio[22258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 30 16:32:19 volumio-pi5 sudo[22655]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 30 16:32:19 volumio-pi5 sudo[22655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:19 volumio-pi5 sudo[22657]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 30 16:32:19 volumio-pi5 sudo[22657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:19 volumio-pi5 sudo[22655]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:19 volumio-pi5 sudo[22657]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:19 volumio-pi5 sudo[22661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 30 16:32:19 volumio-pi5 sudo[22661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:19 volumio-pi5 sudo[22661]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:19 volumio-pi5 volumio[22258]: info: Upmpdcli Daemon Started Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:20 volumio-pi5 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 30 16:32:20 volumio-pi5 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:20 volumio-pi5 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 30 16:32:20 volumio-pi5 go-librespot[22663]: go-librespot daemon starting... Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=info msg="running go-librespot 0.4.0" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="app state loaded" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=info msg="zeroconf server listening on port 32967" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="obtained new client token: AAC7XN/w6pfvpkPWqJuBntmoQPQr7Y2puR3wLurAMsWugCdZOTBiroh3Mc6a3sCcsKbxAqumdHNt2a6OGnHpoJYRvoGaWqWNmKnrl5+zWOLYsnNMjmM9gixcV5E+5CJJi3IO3Fcp6HuxYf3+HRYvrWZiKcQIi+5Y/fz1fdSNPQS1Zjpl3ixnQSoHvveHtTLJv4V+PcCPU4St/OSRaTNivnxDai0zR7spt/cAT3A9iGRiUw2z2CYOv47O6A==" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="completed keyexchange" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="completed challenge" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=info msg="authenticated AP" username="31************************im" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=info msg="authenticated Login5" username="31************************im" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="initializing zeroconf session" username="31************************im" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="dealer connection opened" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=trace msg="starting accesspoint recv loop" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=trace msg="starting dealer recv loop" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=trace msg="received accesspoint ping" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="received connection id: MjE3ZDY3ZWQtZjIz...QkEyMEZBODFFOA==" Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=trace msg="received accesspoint pong ack" Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: CURURI: music-library Dec 30 16:32:20 volumio-pi5 volumio[22258]: error: Failed LSINFO: null Dec 30 16:32:20 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:20+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 30 16:32:20 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:21 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin bluetooth to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin multiroom to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin metavolumio to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin cd_controller to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Starting MyVolumio Remote Streaming Endpoints Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: MyVolumio login type: Token Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Streaming services startup Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Starting Streaming Daemon Dec 30 16:32:22 volumio-pi5 sudo[22672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 30 16:32:22 volumio-pi5 sudo[22672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 30 16:32:22 volumio-pi5 sudo[22672]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:22 volumio-pi5 volumio[22258]: error: Cannot start Volumio Streaming Daemon Dec 30 16:32:22 volumio-pi5 volumio[22258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 30 16:32:22 volumio-pi5 volumio[22258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Initializing connection to go-librespot Websocket Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Connection to go-librespot Websocket established Dec 30 16:32:22 volumio-pi5 go-librespot[22664]: time="2025-12-30T16:32:22+01:00" level=debug msg="new websocket client" Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:22 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:23 volumio-pi5 volumio[22258]: error: MyVolumio Custom Token format not valid, refreshing it Dec 30 16:32:23 volumio-pi5 volumio[22258]: info: MyVolumio login type: Token Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: CURURI: artists:// Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MyVolumio token set successfully Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVOLUMIO: Adding device Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVOLUMIO: Evaluating Server Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MyVolumio Plan changed: premium Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Removing browser output: myVolumio user plan is not superstar Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Removing audio output: Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVOLUMIO: Adding device Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVOLUMIO: Evaluating Server Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Remote config written successfully Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Starting Tunnel 1 Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Starting Tunnel Connection Checker Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Completed starting MyVolumio Plugin Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MYVolumio Device enabled Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: MyVolumio status changed Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Streaming services startup Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: Starting Streaming Daemon Dec 30 16:32:24 volumio-pi5 sudo[22717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 30 16:32:24 volumio-pi5 sudo[22717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 30 16:32:24 volumio-pi5 sudo[22717]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:24 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Dec 30 16:32:24 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 30 16:32:25 volumio-pi5 sudo[22723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 30 16:32:25 volumio-pi5 sudo[22723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 sudo[22723]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 volumio[22258]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: MultiRoom plugin initialized Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: STOPPING SNAPCLIENT Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Snap server stop Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: STOPPING volumioStreaming Dec 30 16:32:25 volumio-pi5 sudo[22740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 30 16:32:25 volumio-pi5 sudo[22740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 sudo[22742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 30 16:32:25 volumio-pi5 sudo[22742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 30 16:32:25 volumio-pi5 sudo[22744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 30 16:32:25 volumio-pi5 sudo[22744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 30 16:32:25 volumio-pi5 sudo[22748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 30 16:32:25 volumio-pi5 sudo[22748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 30 16:32:25 volumio-pi5 sudo[22748]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Preparing to generate the ALSA configuration file Dec 30 16:32:25 volumio-pi5 sudo[22740]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 sudo[22744]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 sudo[22742]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Reading ALSA contributions from plugins. Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Setting Geolocation for MyVolumio to eu6 Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Setting Geolocation for MyVolumio to eu6 Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Removed streaming files Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: SNAPCLIENT STOPPED Dec 30 16:32:25 volumio-pi5 volumio[22258]: error: Cannot start Volumio Streaming Daemon Dec 30 16:32:25 volumio-pi5 volumio[22258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 30 16:32:25 volumio-pi5 volumio[22258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: SNAPSERVER STOPPED Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: volumioStreaming STOPPED Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Asound.conf file written Dec 30 16:32:25 volumio-pi5 sudo[22754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 30 16:32:25 volumio-pi5 sudo[22754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 sudo[22754]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 30 16:32:25 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 30 16:32:25 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 30 16:32:25 volumio-pi5 volumio[22258]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Output device has changed, restarting MPD Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Output device has changed, restarting Shairport Sync Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:25 volumio-pi5 sudo[22762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 30 16:32:25 volumio-pi5 sudo[22762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 sudo[22761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 30 16:32:25 volumio-pi5 sudo[22761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:25 volumio-pi5 sudo[22761]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:25 volumio-pi5 systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 30 16:32:25 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 30 16:32:25 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 30 16:32:25 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 30 16:32:25 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output for this device Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding audio output: Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding audio output: Dec 30 16:32:25 volumio-pi5 systemd[1]: mpd.service: Deactivated successfully. Dec 30 16:32:25 volumio-pi5 systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 30 16:32:25 volumio-pi5 systemd[1]: mpd.socket: Deactivated successfully. Dec 30 16:32:25 volumio-pi5 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 30 16:32:25 volumio-pi5 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 30 16:32:25 volumio-pi5 bluetoothd[1019]: Path / reserved for Adv Monitor app :1.50 Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding METAVOLUMIO REST API Endpoints Dec 30 16:32:25 volumio-pi5 bluetoothd[1019]: Adv Monitor app :1.50 disconnected from D-Bus Dec 30 16:32:25 volumio-pi5 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Preparing CD Folders Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding CD REST API Endpoints Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Starting UDEV Watcher for CD Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: Detecting CD presence with UDEV Dec 30 16:32:25 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 30 16:32:25 volumio-pi5 systemd[1]: Starting mpd.service - Music Player Daemon... Dec 30 16:32:25 volumio-pi5 sudo[22778]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 30 16:32:25 volumio-pi5 sudo[22778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 30 16:32:25 volumio-pi5 sudo[22778]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:26 volumio-pi5 mpd[22783]: 2025-12-30T16:32:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 30 16:32:26 volumio-pi5 systemd[1]: Started mpd.service - Music Player Daemon. Dec 30 16:32:26 volumio-pi5 sudo[22762]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: warn: [cd-plugin] cdspeedctl: device or media not ready Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding inputs REST Endpoints Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Scanning Audio Inputs Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Checking against Known Cards name Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [1767108750630] CoreMusicLibrary::Adding element Loopback Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 30 16:32:30 volumio-pi5 volumio[22258]: Cannot find translation for source Spotify Dec 30 16:32:30 volumio-pi5 volumio[22258]: Cannot find translation for source Loopback Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Checking against Known Cards name Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Checking against Known Cards name Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding Server instance for streaming Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 30 16:32:30 volumio-pi5 volumio[22258]: error: Hi Res Audio Failed Login: Missing Login Data Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 30 16:32:30 volumio-pi5 sudo[22805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 30 16:32:30 volumio-pi5 sudo[22805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 30 16:32:30 volumio-pi5 sudo[22812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 30 16:32:30 volumio-pi5 sudo[22812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 systemd[1]: vtcs.service: Killing process 2374 (vtcs) with signal SIGKILL. Dec 30 16:32:30 volumio-pi5 systemd[1]: vtcs.service: Killing process 2384 (vtcs) with signal SIGKILL. Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 30 16:32:30 volumio-pi5 systemd[1]: vtcs.service: Deactivated successfully. Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding TIDAL REST API Endpoints Dec 30 16:32:30 volumio-pi5 systemd[1]: vtcs.service: Consumed 3.907s CPU time. Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Stopping AccessToken refresher cron for QOBUZ Dec 30 16:32:30 volumio-pi5 sudo[22805]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: AccessToken refresher cron started for QOBUZ Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding QOBUZ REST API Endpoints Dec 30 16:32:30 volumio-pi5 sudo[22812]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Getting Spotify volume Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Updating MyVolumio device info Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 sudo[22815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Updating MyVolumio device info Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 sudo[22815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection error: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Remote connection timeout: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Getting audio outputs on start Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Requesting all other devices output Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Connecting to remote: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Connecting to remote: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 30 16:32:30 volumio-pi5 qobuz-connect[2267]: 20251230 16:32:30.714 [2267.2267] INFO SampleApp: Stopping Local configuration server Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Successfully Added MyVolumio device Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Successfully Added MyVolumio device Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CURURI: playlists Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Listing playlists Dec 30 16:32:30 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MPD Permissions set Dec 30 16:32:30 volumio-pi5 sudo[22818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 30 16:32:30 volumio-pi5 sudo[22818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Spotify volume: 100 Dec 30 16:32:30 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 sudo[22818]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:30 volumio-pi5 volumio[22258]: error: updateQueue error: null Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Pushing audio output on request Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioStop Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreStateMachine::stop Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 16:32:30 volumio-pi5 volumio[22258]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Starting Shairport Sync Dec 30 16:32:30 volumio-pi5 sudo[22834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 30 16:32:30 volumio-pi5 sudo[22834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Found cast device: Google-Nest-Hub-623ddd316aab85cb0addd347103857bc Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding audio output: Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: MRS: Found cast device: Google-Cast-Group-3AE956DAA5654EBC91C8070417518061 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Adding audio output: Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 30 16:32:30 volumio-pi5 systemd[1]: shairport-sync.service: Deactivated successfully. Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 16:32:30 volumio-pi5 systemd[1]: shairport-sync.service: Consumed 1.530s CPU time. Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Preloading song: spotify:track:4lvdfbcMVMHp7oQoAKV2om Dec 30 16:32:30 volumio-pi5 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 30 16:32:30 volumio-pi5 sudo[22834]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Shairport-Sync Started Dec 30 16:32:30 volumio-pi5 sudo[22838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 30 16:32:30 volumio-pi5 sudo[22838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:30 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:30 volumio-pi5 volumio[22258]: SPOTIFY: SPOTIFY VOLUME 100 Dec 30 16:32:30 volumio-pi5 volumio[22258]: SPOTIFY: VOLUMIO VOLUME 5 Dec 30 16:32:30 volumio-pi5 volumio[22258]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Setting Spotify Volume from Volumio: 5 Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Dec 30 16:32:30 volumio-pi5 autossh[2326]: received signal to exit (15) Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Exploding uri spotify:track:4lvdfbcMVMHp7oQoAKV2om in service spop Dec 30 16:32:30 volumio-pi5 volumio[22258]: SPOTIFY: EXPLODING URI:spotify:track:4lvdfbcMVMHp7oQoAKV2om Dec 30 16:32:30 volumio-pi5 systemd[1]: sshtunnel.service: Deactivated successfully. Dec 30 16:32:30 volumio-pi5 systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 30 16:32:30 volumio-pi5 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 30 16:32:30 volumio-pi5 sudo[22838]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:30 volumio-pi5 volumio[22258]: info: Remote SSH Started Dec 30 16:32:30 volumio-pi5 autossh[22853]: port set to 0, monitoring disabled Dec 30 16:32:30 volumio-pi5 autossh[22853]: starting ssh (count 1) Dec 30 16:32:30 volumio-pi5 autossh[22853]: ssh child pid is 22858 Dec 30 16:32:31 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Successfully Updated MyVolumio device Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:31 volumio-pi5 volumio[22258]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.iwGYFmlYwHW4weRR1Lmubn3A7vF2.cadfcee65ca27700831b62bf68b9649c.state.status' Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Successfully Updated MyVolumio device Dec 30 16:32:31 volumio-pi5 volumiossh-tunnel[22858]: Warning: Permanently added '[eu6.myvolumio.org]:2222' (RSA) to the list of known hosts. Dec 30 16:32:31 volumio-pi5 volumio[22258]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4lvdfbcMVMHp7oQoAKV2om","service":"spop","name":"Epica Oxygene - Live","artist":"Jean-Michel Jarre","album":"VERSAILLES 400 LIVE","type":"song","duration":194,"albumart":"https://i.scdn.co/image/ab67616d0000b273e464b02282870a66bb7ddcd6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: MRS: Pushing audio output on request Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Discovery: Disconnected from remote: 192.168.1.170 Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: CURURI: music-library Dec 30 16:32:31 volumio-pi5 volumio[22258]: error: Failed LSINFO: null Dec 30 16:32:31 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:32 volumio-pi5 systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 30 16:32:32 volumio-pi5 systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 30 16:32:32 volumio-pi5 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 30 16:32:32 volumio-pi5 sudo[22815]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: Executing endpoint qc_getconfig Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.208 [22859.22859] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.210 [22859.22859] INFO VolumeManager: [0xb97268]: Setting new playback volume: 75 Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.210 [22859.22859] INFO VolumeManager: [0xb97268]: Setting new mute state: 0 Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.210 [22859.22859] INFO QobuzConnect: [0xb97c38]: Client initialized! Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.211 [22859.22859] INFO SampleApp: Starting Avahi advertising, name: Volumio PI5, service name: _qobuz-connect._tcp Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.219 [22859.22859] INFO LocalConfigManager: [0xb96b48]: Starting Local Configuration server Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.219 [22859.22859] INFO SampleApp: Starting Local configuration server Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.220 [22859.22859] INFO SampleApp: Connected to UNIX socket client 0xb81818 Dec 30 16:32:32 volumio-pi5 qobuz-connect[22859]: 20251230 16:32:32.359 [22859.22859] INFO SampleApp: Playback volume changed: 75 Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:32 volumio-pi5 volumio[22258]: SPOTIFY: SETTING SPOTIFY VOLUME 5 Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: Sending Spotify command with payload to local API: /player/volume Dec 30 16:32:32 volumio-pi5 volumio[22258]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: MRS: Pushing audio output on request Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:32 volumio-pi5 volumio[22258]: info: Discovery: Connected to remote: 192.168.1.170 Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: TidalConnect service stoped! Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 30 16:32:33 volumio-pi5 sudo[22874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 30 16:32:33 volumio-pi5 sudo[22874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:33 volumio-pi5 systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 30 16:32:33 volumio-pi5 sudo[22874]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:33 volumio-pi5 sudo[22878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 30 16:32:33 volumio-pi5 sudo[22878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 30 16:32:33 volumio-pi5 systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 30 16:32:33 volumio-pi5 systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 30 16:32:33 volumio-pi5 systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:33 volumio-pi5 systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 30 16:32:33 volumio-pi5 mpd_monitor.sh[22882]: MPD Monitor Service: Starting MPD Monitor Service Dec 30 16:32:33 volumio-pi5 sudo[22878]: pam_unix(sudo:session): session closed for user root Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Successfully started MPD Monitor Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Executing endpoint tc_getconfig Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 30 16:32:33 volumio-pi5 vtcs[22879]: STARTING TidalConnect services, version: 1.5.2.56 Dec 30 16:32:33 volumio-pi5 vtcs[22879]: STARTED TidalConnect services. Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Executing endpoint tc_connect Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: Connecting to TidalConnect Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::servicePushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:33 volumio-pi5 volumio[22258]: 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} Dec 30 16:32:33 volumio-pi5 volumio[22258]: verbose: CURRENT POSITION 0 Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::syncState stateService stop Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::syncState currentStatus stop Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: No code Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::servicePushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CorePlayQueue::getTrack 0 Dec 30 16:32:33 volumio-pi5 volumio[22258]: 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} Dec 30 16:32:33 volumio-pi5 volumio[22258]: verbose: CURRENT POSITION 0 Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::syncState stateService stop Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::syncState currentStatus stop Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: No code Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status undefined Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status undefined Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status undefined Dec 30 16:32:33 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status undefined Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:33 volumio-pi5 volumio[22258]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.iwGYFmlYwHW4weRR1Lmubn3A7vF2.cadfcee65ca27700831b62bf68b9649c.state.status' Dec 30 16:32:33 volumio-pi5 volumio[22258]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.iwGYFmlYwHW4weRR1Lmubn3A7vF2.cadfcee65ca27700831b62bf68b9649c.state.status' Dec 30 16:32:33 volumio-pi5 volumio[22258]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.iwGYFmlYwHW4weRR1Lmubn3A7vF2.cadfcee65ca27700831b62bf68b9649c.state.status' Dec 30 16:32:33 volumio-pi5 volumio[22258]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.iwGYFmlYwHW4weRR1Lmubn3A7vF2.cadfcee65ca27700831b62bf68b9649c.state.status' Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: TidalConnect service started! Dec 30 16:32:36 volumio-pi5 volumio[22258]: [Metrics] CommandRouter: 27s 542.36ms Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumiosetStartupVolume Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: VolumeController:: Setting startup Volume 5 Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: VolumeController::SetAlsaVolume5 Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::Close All Modals sent Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::Close All Modals sent Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreStateMachine::pushState Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioPushState Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output update for this device Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: MRS: Pushing multiroomSync output Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: PeppyMeterBasic ---peppymeterbasic status Dec 30 16:32:36 volumio-pi5 volumio[22258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Dec 30 16:32:36 volumio-pi5 volumio[22258]: SPOTIFY: SPOTIFY VOLUME 5 Dec 30 16:32:36 volumio-pi5 volumio[22258]: SPOTIFY: VOLUMIO VOLUME 5 Dec 30 16:32:36 volumio-pi5 volumio[22258]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: CURURI: albums:// Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: listAlbums - loading Albums from cache Dec 30 16:32:36 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:37 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 30 16:32:37 volumio-pi5 volumio[22258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Dec 30 16:32:37 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetState Dec 30 16:32:37 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 30 16:32:37 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 30 16:32:37 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: In handleBrowseUri, curUri=spotify Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:41 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 30 16:32:42 volumio-pi5 volumio-remote-updater[1037]: Test mode disabled Dec 30 16:32:42 volumio-pi5 volumio-remote-updater[1037]: Alpha mode disabled Dec 30 16:32:42 volumio-pi5 volumio-remote-updater[1037]: Alpha legacy test mode disabled Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::volumioGetBrowseSources Dec 30 16:32:42 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 30 16:32:43 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 16:32:43 volumio-pi5 volumio[22258]: info: In handleBrowseUri, curUri=spotify/myalbums Dec 30 16:32:43 volumio-pi5 volumio[22258]: info: BOOT COMPLETED Dec 30 16:32:43 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:46 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 16:32:46 volumio-pi5 volumio[22258]: info: In handleBrowseUri, curUri=spotify/playlists Dec 30 16:32:46 volumio-pi5 volumio[22258]: info: Preload queue cleared Dec 30 16:32:47 volumio-pi5 volumio[22258]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Dec 30 16:32:47 volumio-pi5 volumio[22258]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:2z3TbsU1pZL2x4r3XF1aez Dec 30 16:32:48 volumio-pi5 volumio[22258]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 16:32:48 volumio-pi5 volumio[22258]: TypeError: Cannot read properties of null (reading '0') Dec 30 16:32:48 volumio-pi5 volumio[22258]: at /data/plugins/music_service/spop/index.js:2507:56 Dec 30 16:32:48 volumio-pi5 volumio[22258]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Dec 30 16:32:48 volumio-pi5 volumio[22258]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 30 16:32:48 volumio-pi5 sudo[22941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-30 16:31' Dec 30 16:32:48 volumio-pi5 sudo[22941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"