Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:00 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:00 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:00 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:00 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:01 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:01 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:01 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:01 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:01 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:01 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:01 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:01 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:03 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 16 11:59:08 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 16 11:59:12 volumio2 volumio[1066]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 16 11:59:12 volumio2 volumio[1066]: info: Received Get System Version Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 11:59:12 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:12 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:12 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:12 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:15 volumio2 volumio[1066]: info: Enabling plugin spop Jun 16 11:59:15 volumio2 volumio[1066]: info: Loading plugin "spop"... Jun 16 11:59:16 volumio2 volumio[1066]: info: PLUGIN START: spop Jun 16 11:59:16 volumio2 volumio[1066]: info: Creating Spotify config file Jun 16 11:59:16 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 11:59:16 volumio2 volumio[1066]: info: Done. Jun 16 11:59:16 volumio2 volumio[1066]: info: Spotify config file written Jun 16 11:59:16 volumio2 sudo[3628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 16 11:59:16 volumio2 sudo[3628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:16 volumio2 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. Jun 16 11:59:16 volumio2 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. Jun 16 11:59:16 volumio2 volumio[1066]: info: No need to fix Spotify hosts Jun 16 11:59:16 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 16 11:59:16 volumio2 go-librespot[3630]: go-librespot daemon starting... Jun 16 11:59:16 volumio2 sudo[3628]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=info msg="running go-librespot 0.2.0" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=debug msg="no app state found" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=debug msg="stored credentials not found" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=info msg="generated new device id: 4cc2a5066fb3647ae09c57a25c9d34b8fe246f52" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 16 11:59:16 volumio2 go-librespot[3631]: time="2025-06-16T11:59:16+02:00" level=info msg="zeroconf server listening on port 42551" Jun 16 11:59:16 volumio2 volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 16 11:59:17 volumio2 volumio[1066]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 16 11:59:17 volumio2 volumio[1066]: info: Received Get System Version Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 11:59:17 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:17 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:17 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:19 volumio2 volumio[1066]: info: go-librespot daemon successfully initialized Jun 16 11:59:19 volumio2 systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 16 11:59:22 volumio2 volumio[1066]: info: Received OAUTH Data Jun 16 11:59:22 volumio2 volumio[1066]: info: Executing Spotify Oauth Login Jun 16 11:59:22 volumio2 volumio[1066]: info: Saving Spotify Refresh Token Jun 16 11:59:22 volumio2 volumio[1066]: info: Initializing connection to go-librespot Websocket Jun 16 11:59:22 volumio2 go-librespot[3631]: time="2025-06-16T11:59:22+02:00" level=debug msg="new websocket client" Jun 16 11:59:22 volumio2 volumio[1066]: info: Connection to go-librespot Websocket established Jun 16 11:59:22 volumio2 sudo[3656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 11:59:22 volumio2 sudo[3656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:22 volumio2 sudo[3656]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:22 volumio2 sudo[3658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 11:59:22 volumio2 sudo[3658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:22 volumio2 sudo[3658]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:22 volumio2 volumio[1066]: verbose: New Socket.io Connection to 192.168.1.108 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 15; 2312DRA50G Build/AQ3A.240912.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.89 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:22 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 16 11:59:22 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:22 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:22 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:22 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:22 volumio2 volumio[1066]: info: Listing playlists Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 16 11:59:22 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: BQBNTdIOYxL1mcBXU2q5AJn2XHlW6smabJ2QG7dxlkMENmg7v47szECl9pSTx6xjpFjrDRvhxSk38SslROTC-oEED0Jgqrq28xczanTylVbF64pDDzoV4-mUDHy3F1ing2d7E9Ah0hG7Q0dgqCTMaXmJgjipci5Gn2gXfsqAMCuH7qOGxeTtBSwT6-tObtI8PA47SiLA5g1-I7V80gmuMJpXz8f6vaWLO05V88njbdz54XULhBFZkIupA4a_iEcycPMwUlefH9OD3k35I1YVt1w Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 11:59:23 volumio2 volumio[1066]: info: New Spotify access token = BQBNTdIOYxL1mcBXU2q5AJn2XHlW6smabJ2QG7dxlkMENmg7v47szECl9pSTx6xjpFjrDRvhxSk38SslROTC-oEED0Jgqrq28xczanTylVbF64pDDzoV4-mUDHy3F1ing2d7E9Ah0hG7Q0dgqCTMaXmJgjipci5Gn2gXfsqAMCuH7qOGxeTtBSwT6-tObtI8PA47SiLA5g1-I7V80gmuMJpXz8f6vaWLO05V88njbdz54XULhBFZkIupA4a_iEcycPMwUlefH9OD3k35I1YVt1w Jun 16 11:59:23 volumio2 volumio[1066]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: User informations: {"country":"PL","display_name":"raffal0073","email":"gringios@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/raffal0073"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/raffal0073","id":"raffal0073","images":[],"product":"free","type":"user","uri":"spotify:user:raffal0073"} Jun 16 11:59:23 volumio2 volumio[1066]: info: Creating Spotify config file Jun 16 11:59:23 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 11:59:23 volumio2 volumio[1066]: info: Spotify config file written Jun 16 11:59:23 volumio2 sudo[3662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 16 11:59:23 volumio2 sudo[3662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:23 volumio2 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jun 16 11:59:23 volumio2 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jun 16 11:59:23 volumio2 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 16 11:59:23 volumio2 volumio[1066]: info: Connection to go-librespot Websocket closed Jun 16 11:59:23 volumio2 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 16 11:59:23 volumio2 go-librespot[3664]: go-librespot daemon starting... Jun 16 11:59:23 volumio2 sudo[3662]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:23 volumio2 go-librespot[3665]: time="2025-06-16T11:59:23+02:00" level=info msg="running go-librespot 0.2.0" Jun 16 11:59:23 volumio2 go-librespot[3665]: time="2025-06-16T11:59:23+02:00" level=debug msg="app state loaded" Jun 16 11:59:23 volumio2 go-librespot[3665]: time="2025-06-16T11:59:23+02:00" level=debug msg="stored credentials not found" Jun 16 11:59:23 volumio2 go-librespot[3665]: time="2025-06-16T11:59:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: BQDMzySYeC9dtGKUvOj8RpyuqHGn5ELqU2A1wZqm0tZ2pdm3pGy5jnxhWjpQ9vnZhIo-uysBk46TvM7TG68J9pDAc36hcbBQYj4z-WaAXPDGstV7rRDumE4RGwDIJc3AGvvryKC7EP0-EZVL8kkQboghmlRx0TAHHG-HbU7AWsTzJZjNZpsNhES36Se7i_KU6oYXDV8Cp8t2LEswrNBlgmqTgXTyrD5l2VAYt-3TfzMB94sG9JNzhkg-zNkMUQGCiBo8XcSIARrj-id745af9Kk Jun 16 11:59:23 volumio2 volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 16 11:59:23 volumio2 volumio[1066]: info: New Spotify access token = BQDMzySYeC9dtGKUvOj8RpyuqHGn5ELqU2A1wZqm0tZ2pdm3pGy5jnxhWjpQ9vnZhIo-uysBk46TvM7TG68J9pDAc36hcbBQYj4z-WaAXPDGstV7rRDumE4RGwDIJc3AGvvryKC7EP0-EZVL8kkQboghmlRx0TAHHG-HbU7AWsTzJZjNZpsNhES36Se7i_KU6oYXDV8Cp8t2LEswrNBlgmqTgXTyrD5l2VAYt-3TfzMB94sG9JNzhkg-zNkMUQGCiBo8XcSIARrj-id745af9Kk Jun 16 11:59:23 volumio2 volumio[1066]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=info msg="zeroconf server listening on port 35049" Jun 16 11:59:24 volumio2 volumio[1066]: SPOTIFY: User informations: {"country":"PL","display_name":"raffal0073","email":"gringios@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/raffal0073"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/raffal0073","id":"raffal0073","images":[],"product":"free","type":"user","uri":"spotify:user:raffal0073"} Jun 16 11:59:24 volumio2 volumio[1066]: info: Spotify Successfully logged in Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 16 11:59:24 volumio2 volumio[1066]: info: [1750067964062] CoreMusicLibrary::Adding element Spotify Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 11:59:24 volumio2 volumio[1066]: Cannot find translation for source Spotify Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:24 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:24 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:24 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:24 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="obtained new client token: AAAsCXIIRNGTuLkPIsrtqUX4UVDdZ8FwDVooyTW94NPHqKaP9FetCBTrEDgrbFhF+jxZ6H3PkUZA+e+KnIssycVR3SXLvpY8on1yjZyvHVAVWBBy0+R9wnbXsYE71WenqrO9THHuB6slCwa0y5SeCjAmZFs8LTc85Ald+CH0BsNmMws/AlamJlVvDfVSNicwdDzwzXWuaxsgHJgmQ+q+5GDcbNu/YvtPMXCsYQGIohrwuWzk/+svSuafdw==" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="completed keyexchange" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=debug msg="completed challenge" Jun 16 11:59:24 volumio2 go-librespot[3665]: time="2025-06-16T11:59:24+02:00" level=info msg="authenticated AP as raffal0073" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=info msg="authenticated Login5 as raffal0073" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="stored credentials for raffal0073" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="initializing zeroconf session, username: raffal0073" Jun 16 11:59:25 volumio2 volumio[1066]: info: Getting Spotify volume Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:25 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:25 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:25 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:25 volumio2 volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:25 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:25 volumio2 volumio[1066]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jun 16 11:59:25 volumio2 volumio[1066]: SPOTIFY: SPOTIFY VOLUME undefined Jun 16 11:59:25 volumio2 volumio[1066]: SPOTIFY: VOLUMIO VOLUME 86 Jun 16 11:59:25 volumio2 volumio[1066]: info: Aligning Spotify Volume to Volumio Volume Jun 16 11:59:25 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:25 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:25 volumio2 volumio[1066]: info: Setting Spotify Volume from Volumio: 86 Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="dealer connection opened" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=trace msg="starting accesspoint recv loop" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=trace msg="starting dealer recv loop" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=trace msg="received accesspoint ping" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 16 11:59:25 volumio2 volumio[1066]: info: Spotify volume: 100 Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="received connection id: M2Y0NzQ2YTEtYmIxZi00MjAyLTg1NTItZmIwMGY1NjQ0M2RiK2RlYWxlcit0Y3A6Ly8wYWNhNTgxOC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRDlEQjY3MkREQ0ZFNjBBNjhCQzgyMzU2QzgyNTIxOUMwRjkzRUVEREFENDY0RTYxQzBCQkZGNTQwNDcxRUVCQw==" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=trace msg="received accesspoint pong ack" Jun 16 11:59:25 volumio2 go-librespot[3665]: time="2025-06-16T11:59:25+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 16 11:59:26 volumio2 volumio[1066]: info: Initializing connection to go-librespot Websocket Jun 16 11:59:26 volumio2 go-librespot[3665]: time="2025-06-16T11:59:26+02:00" level=debug msg="new websocket client" Jun 16 11:59:26 volumio2 volumio[1066]: info: Connection to go-librespot Websocket established Jun 16 11:59:26 volumio2 volumio[1066]: info: go-librespot daemon successfully initialized Jun 16 11:59:26 volumio2 volumio[1066]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Jun 16 11:59:26 volumio2 volumio[1066]: info: Sending Spotify command with payload to local API: /player/volume Jun 16 11:59:26 volumio2 go-librespot[3665]: time="2025-06-16T11:59:26+02:00" level=debug msg="update volume to 56360/65535" Jun 16 11:59:27 volumio2 go-librespot[3665]: time="2025-06-16T11:59:27+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 16 11:59:27 volumio2 go-librespot[3665]: time="2025-06-16T11:59:27+02:00" level=trace msg="emitting websocket event: volume" Jun 16 11:59:27 volumio2 volumio[1066]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Jun 16 11:59:27 volumio2 volumio[1066]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Jun 16 11:59:29 volumio2 volumio[1066]: info: Getting Spotify volume Jun 16 11:59:29 volumio2 volumio[1066]: info: Spotify volume: 86 Jun 16 11:59:29 volumio2 volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jun 16 11:59:29 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:29 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:29 volumio2 volumio[1066]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jun 16 11:59:29 volumio2 volumio[1066]: info: Initializing connection to go-librespot Websocket Jun 16 11:59:29 volumio2 go-librespot[3665]: time="2025-06-16T11:59:29+02:00" level=debug msg="new websocket client" Jun 16 11:59:29 volumio2 volumio[1066]: info: Connection to go-librespot Websocket established Jun 16 11:59:32 volumio2 volumio[1066]: info: Getting Spotify volume Jun 16 11:59:32 volumio2 volumio[1066]: info: Spotify volume: 86 Jun 16 11:59:32 volumio2 volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jun 16 11:59:32 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:32 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:32 volumio2 volumio[1066]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jun 16 11:59:32 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:32 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:33 volumio2 sudo[3689]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 11:59:33 volumio2 sudo[3689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:33 volumio2 sudo[3689]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:33 volumio2 sudo[3691]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 11:59:33 volumio2 sudo[3691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:33 volumio2 sudo[3691]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:33 volumio2 volumio[1066]: verbose: New Socket.io Connection to 192.168.1.108 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 15; 2312DRA50G Build/AQ3A.240912.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.89 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Jun 16 11:59:33 volumio2 sudo[3695]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 16 11:59:33 volumio2 sudo[3695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:33 volumio2 sudo[3695]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:33 volumio2 sudo[3697]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 16 11:59:33 volumio2 sudo[3697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 16 11:59:33 volumio2 sudo[3697]: pam_unix(sudo:session): session closed for user root Jun 16 11:59:33 volumio2 volumio[1066]: verbose: New Socket.io Connection to 192.168.1.108 from 192.168.1.102 UA: Mozilla/5.0 (Linux; Android 15; 2312DRA50G Build/AQ3A.240912.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/137.0.7151.89 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Jun 16 11:59:33 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:34 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 16 11:59:34 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:34 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:34 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:34 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:34 volumio2 volumio[1066]: info: Listing playlists Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 16 11:59:34 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:35 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:35 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:35 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:36 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 11:59:36 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:36 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:36 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:36 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:36 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:36 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:36 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:40 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetQueue Jun 16 11:59:40 volumio2 volumio[1066]: info: CoreStateMachine::getQueue Jun 16 11:59:40 volumio2 volumio[1066]: info: CorePlayQueue::getQueue Jun 16 11:59:42 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 16 11:59:42 volumio2 volumio[1066]: info: In handleBrowseUri, curUri=spotify Jun 16 11:59:42 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:42 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:42 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:42 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:43 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 16 11:59:44 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 16 11:59:44 volumio2 volumio[1066]: info: In handleBrowseUri, curUri=spotify/playlists Jun 16 11:59:47 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:47 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:47 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:47 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:47 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:47 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:49 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 16 11:59:51 volumio2 volumio[1066]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 16 11:59:51 volumio2 volumio[1066]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 16 11:59:51 volumio2 volumio[1066]: info: Received Get System Version Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 11:59:51 volumio2 volumio[1066]: info: Received Get System Info Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:51 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:51 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:51 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 11:59:54 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4tcauy2xyIv1q0ckvQmc4H Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:37Q5anxoGWYdRsyeXkkNoI Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5tdKaKLnC4SgtDZ6RlWeal Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:7wuJGgpTNzbUyn26IOY6rj Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6mYrhCAGWzTdF8QnKuchXM Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3SnGymj6ijE2iuUfWxLo1q Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4w3tQBXhn5345eUXDGBWZG Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:18DfMhEx4ddoreHrvZDF6Q Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0odIT9B9BvOCnXfS0e4lB5 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2EGaDf0cPX789H3LNeB03D Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2Cdvbe2G4hZsnhNMKyGrie Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6pPWRBubXOBAHnjl5ZIujB Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:7LNP6YNYDeMgBeG4JBfAdq Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:31H6au3jhblhr6MMJiXnCq Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4S1VYqwfkLit9mKVY3MXoo Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5zWZ9iNevP0397xB3jWV2z Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5luOvrlnzfvJQdQjrScVj4 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6r8k1vznHrzlEKYxL4dZEe Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2MaBAGBIttgv86bYytdx1f Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1ot6jEe4w4hYnsOPjd3xKQ Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2VpdG2QLhVv6qAPdDt9Ipr Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1UvTPXlImVd4jcucK4qJwb Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2v7ywbUzCgcVohHaKUcacV Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1aYkkrAbPmMuorVz5HWIqE Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6QLspHLCLftSGPa6vNzKuo Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1CtAzw53AIXKjAemxy4b1j Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2aEuA8PSqLa17Y4hKPj5rr Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4WpmwEdc4RBos8W8icSSxW Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3cbV252akVZInSvJk7jAYX Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0IWtEFQBwRHaMXZQtGEVcM Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4ByEFOBuLXpCqvO1kw8Wdm Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1exLL81vN8mD55M9HMOt1t Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:7BdXRaSlGAzhySfuW3y8h5 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0GONea6G2XdnHWjNZd6zt3 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5vmRQ3zELMLUQPo2FLQ76x Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6JNJERZGJwDVgkmbohBw7u Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3X7uFMzJrEE0sxn62qd8Ch Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3FdHgoJbH3DXNtGLh56pFu Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:77NNZQSqzLNqh2A9JhLRkg Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5fy4vfEtv6lzqLx2Mt7stF Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:098JUtp63d1Hsge11VuoD2 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1NCuYqMc8hKMb4cpNTcJbD Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5Hk4Mpex0s2ndUpDQ5v2rU Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1JLn8RhQzHz3qDqsChcmBl Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6apPqjW8ezpKEicAkkBlvO Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1wrT33b6HuKlpk9ziscEUY Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1F43XlPBiwAUUIhrUGzylO Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2tUBqZG2AbRi7Q0BIrVrEj Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:07ABETRdek3ACMpRPvQuaT Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4LFwNJWoj74Yd71fIr1W8x Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:50XXRUFNjs85P0MjCZ1c9X Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:21qnJAMtzC6S5SESuqQLEK Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6kk07URPWTiRzULynSOVrs Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3elV4E1GOKfF0MVRgdp6eU Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2KH16WveTQWT6KOG9Rg6e2 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3MrRksHupTVEQ7YbA0FsZK Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0ire4j2mcGovF5JA1D2cTp Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5Hcl1reJnHIfJBbCcglaKR Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1TfqLAPs4K3s2rJMoCokcS Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2avaSeKHI5l4sLruVfLdi2 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:00FDHurakzVEiPutdUxXXq Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6CTnIURom7GvzLqXuFHrXA Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0uMMLry3hzWGn3q3loqMkm Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5XcZRgJv3zMhTqCyESjQrF Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2vz1CsL5WBsbpBcwgboTAw Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6sn3FHCq2csvNkq2h9Au8V Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1kIu9zpYtWjgrLlsactlna Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5NoUgO4Kr93QymQGQlBC7b Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1c9dnQbOzw01ID7X2IsYOE Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1KU5EHSz04JhGg3rReGJ0N Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0X1sqQ652p1sceKM2nJlIJ Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5dRQUolXAVX3BbCiIxmSsf Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:7Ewz6bJ97vUqk5HdkvguFQ Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0e3yhVeNaTfKIWQRw9U9sY Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:54b8qPFqYqIndfdxiLApea Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:37ZJ0p5Jm13JPevGcx4SkF Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0PXw9NKvolWTo7U9JkNzmc Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1GbyYL0B0Mjn3kSbrEwKKI Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1mskmld5ZKEhRaNvYVPoqZ Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:5NwkWwfRJaT55hEPtCmJHx Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:45r7mbXRbpFAYZavAoX6tk Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6r20M5DWYdIoCDmDViBxuz Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4NH4xiPQ7TqNGqj6pZV4ki Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3Z2tPWiNiIpg8UMMoowHIk Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2RWFncSWZEhSRRifqiDNVV Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3NYCaxkggl0Hh8vQptSUvV Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:1pTGc8pwyo6xtgXBKCBcFn Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4nFNJmjfgBF7jwv2oBC45b Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4d6eqRtpDX7tydHJGDZUBQ Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0ikz6tENMONtK6qGkOrU3c Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:4euAGZTszWPrriggYK0HG9 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6ADSaE87h8Y3lccZlBJdXH Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:7FwBtcecmlpc1sLySPXeGE Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2WfaOiMkCvy7F5fcp2zZ8L Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:6WK9dVrRABMkUXFLNlgWFh Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:2IJftBfq7pJ43tfnOR0RB3 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:3iB8eciGU9vZkaDYkz7Ir9 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0dOg1ySSI7NkpAe89Zo0b9 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:05wIrZSwuaVWhcv5FfqeH0 Jun 16 11:59:54 volumio2 volumio[1066]: info: Preloading song: spotify:track:0qi4b1l0eT3jpzeNHeFXDT Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:4tcauy2xyIv1q0ckvQmc4H in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:4tcauy2xyIv1q0ckvQmc4H Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:37Q5anxoGWYdRsyeXkkNoI in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:37Q5anxoGWYdRsyeXkkNoI Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:5tdKaKLnC4SgtDZ6RlWeal in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:5tdKaKLnC4SgtDZ6RlWeal Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:7wuJGgpTNzbUyn26IOY6rj in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:7wuJGgpTNzbUyn26IOY6rj Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","service":"spop","name":"Material Girl - 2024 Remaster","artist":"Madonna","album":"Material Girl (2024 Remaster)","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b273f7642d9a8207443acf9b5466","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:6mYrhCAGWzTdF8QnKuchXM in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:6mYrhCAGWzTdF8QnKuchXM Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:3SnGymj6ijE2iuUfWxLo1q in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:3SnGymj6ijE2iuUfWxLo1q Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:4w3tQBXhn5345eUXDGBWZG in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:4w3tQBXhn5345eUXDGBWZG Jun 16 11:59:54 volumio2 volumio[1066]: info: Exploding uri spotify:track:18DfMhEx4ddoreHrvZDF6Q in service spop Jun 16 11:59:54 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:18DfMhEx4ddoreHrvZDF6Q Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:0odIT9B9BvOCnXfS0e4lB5 in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:0odIT9B9BvOCnXfS0e4lB5 Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37Q5anxoGWYdRsyeXkkNoI","service":"spop","name":"Heaven Is A Place On Earth","artist":"Belinda Carlisle","album":"Greatest Vol.1 - Belinda Carlisle","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b273e0f0aa947770fe74049dbba3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2EGaDf0cPX789H3LNeB03D in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2EGaDf0cPX789H3LNeB03D Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2Cdvbe2G4hZsnhNMKyGrie in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2Cdvbe2G4hZsnhNMKyGrie Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7wuJGgpTNzbUyn26IOY6rj","service":"spop","name":"Total Eclipse of the Heart","artist":"Bonnie Tyler","album":"The Very Best of Bonnie Tyler","type":"song","duration":267,"albumart":"https://i.scdn.co/image/ab67616d0000b2738cefe8e2f2cfd63ce073fa96","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:6pPWRBubXOBAHnjl5ZIujB in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:6pPWRBubXOBAHnjl5ZIujB Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:7LNP6YNYDeMgBeG4JBfAdq in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:7LNP6YNYDeMgBeG4JBfAdq Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5tdKaKLnC4SgtDZ6RlWeal","service":"spop","name":"How Will I Know","artist":"Whitney Houston","album":"Whitney Houston","type":"song","duration":269,"albumart":"https://i.scdn.co/image/ab67616d0000b2739015296f9afabfc102989521","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:31H6au3jhblhr6MMJiXnCq in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:31H6au3jhblhr6MMJiXnCq Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3SnGymj6ijE2iuUfWxLo1q","service":"spop","name":"I'm Coming Out","artist":"Diana Ross","album":"Diana","type":"song","duration":323,"albumart":"https://i.scdn.co/image/ab67616d0000b273abc5193decc1a2984a93f31e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4w3tQBXhn5345eUXDGBWZG","service":"spop","name":"9 to 5","artist":"Dolly Parton","album":"9 To 5 And Odd Jobs","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b273060ccf36ab5b0e0a739799ec","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:4S1VYqwfkLit9mKVY3MXoo in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:4S1VYqwfkLit9mKVY3MXoo Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:18DfMhEx4ddoreHrvZDF6Q","service":"spop","name":"The Power of Love","artist":"Jennifer Rush","album":"The Power Of Love: The Best Of Jennifer Rush","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273b3030d635fdba26d12279145","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0odIT9B9BvOCnXfS0e4lB5","service":"spop","name":"Bette Davis Eyes","artist":"Kim Carnes","album":"Mistaken Identity","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2738ccc17f29764d812062204a8","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:5zWZ9iNevP0397xB3jWV2z in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:5zWZ9iNevP0397xB3jWV2z Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2EGaDf0cPX789H3LNeB03D","service":"spop","name":"Cruel Summer","artist":"Bananarama","album":"Bananarama (Collector's Edition)","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b273b20af9c8ff56d8b178cefec0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:5luOvrlnzfvJQdQjrScVj4 in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:5luOvrlnzfvJQdQjrScVj4 Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Cdvbe2G4hZsnhNMKyGrie","service":"spop","name":"I Love Rock 'N Roll","artist":"Joan Jett & the Blackhearts","album":"I Love Rock 'N' Roll (Expanded Edition)","type":"song","duration":175,"albumart":"https://i.scdn.co/image/ab67616d0000b2733c73b2e0a6aa490736f19751","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:6r8k1vznHrzlEKYxL4dZEe in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:6r8k1vznHrzlEKYxL4dZEe Jun 16 11:59:55 volumio2 go-librespot[3665]: time="2025-06-16T11:59:55+02:00" level=trace msg="sent dealer ping" Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LNP6YNYDeMgBeG4JBfAdq","service":"spop","name":"(I'll Never Be) Maria Magdalena - Single Verison","artist":"Sandra","album":"Ten On One","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b2731ade47900d03a0276737982b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6pPWRBubXOBAHnjl5ZIujB","service":"spop","name":"The Best","artist":"Tina Turner","album":"Foreign Affair","type":"song","duration":329,"albumart":"https://i.scdn.co/image/ab67616d0000b273a04b4373fd72bf81c8784adf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2MaBAGBIttgv86bYytdx1f in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2MaBAGBIttgv86bYytdx1f Jun 16 11:59:55 volumio2 go-librespot[3665]: time="2025-06-16T11:59:55+02:00" level=trace msg="received dealer pong" Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:31H6au3jhblhr6MMJiXnCq","service":"spop","name":"Hungry Eyes - From \"Dirty Dancing\" Soundtrack","artist":"Eric Carmen","album":"The Definitive Collection","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b27356daa802ddbaedf04e8123cc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:1ot6jEe4w4hYnsOPjd3xKQ in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:1ot6jEe4w4hYnsOPjd3xKQ Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2VpdG2QLhVv6qAPdDt9Ipr in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2VpdG2QLhVv6qAPdDt9Ipr Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5zWZ9iNevP0397xB3jWV2z","service":"spop","name":"Brother Louie","artist":"Modern Talking","album":"Ready For Romance","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273be1421122cef4940f500ac06","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:1UvTPXlImVd4jcucK4qJwb in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:1UvTPXlImVd4jcucK4qJwb Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2MaBAGBIttgv86bYytdx1f","service":"spop","name":"Listen To Your Heart","artist":"Roxette","album":"Look Sharp!","type":"song","duration":328,"albumart":"https://i.scdn.co/image/ab67616d0000b27322c3c99e7aa0ba6cd08a6be6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2v7ywbUzCgcVohHaKUcacV in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2v7ywbUzCgcVohHaKUcacV Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6r8k1vznHrzlEKYxL4dZEe","service":"spop","name":"La Isla Bonita","artist":"Madonna","album":"True Blue","type":"song","duration":242,"albumart":"https://i.scdn.co/image/ab67616d0000b273de3094d98b62340d3268c7bc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:1aYkkrAbPmMuorVz5HWIqE in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:1aYkkrAbPmMuorVz5HWIqE Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ot6jEe4w4hYnsOPjd3xKQ","service":"spop","name":"I'm So Excited","artist":"The Pointer Sisters","album":"So Excited! (Expanded Edition)","type":"song","duration":230,"albumart":"https://i.scdn.co/image/ab67616d0000b2734650ca0a8f88129d4667acc5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:6QLspHLCLftSGPa6vNzKuo in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:6QLspHLCLftSGPa6vNzKuo Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2VpdG2QLhVv6qAPdDt9Ipr","service":"spop","name":"Lambada - Original Radio Edit","artist":"Kaoma","album":"World Beat","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b2736369dbebc592ecad70b7f7d5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","service":"spop","name":"Forever Young","artist":"Alphaville","album":"Forever Young","type":"song","duration":226,"albumart":"https://i.scdn.co/image/ab67616d0000b273b9c4979446c4d39bc08e9503","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:1CtAzw53AIXKjAemxy4b1j in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:1CtAzw53AIXKjAemxy4b1j Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5luOvrlnzfvJQdQjrScVj4","service":"spop","name":"Live Is Life (Digitally Remastered) (Single Version)","artist":"Opus","album":"Live Is Life","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b273680c56a0f621a43edf19046a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:55 volumio2 volumio[1066]: info: Exploding uri spotify:track:2aEuA8PSqLa17Y4hKPj5rr in service spop Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:2aEuA8PSqLa17Y4hKPj5rr Jun 16 11:59:55 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1UvTPXlImVd4jcucK4qJwb","service":"spop","name":"(I've Had) The Time of My Life - From \"Dirty Dancing\" Soundtrack","artist":"Bill Medley","album":"LOVE","type":"song","duration":289,"albumart":"https://i.scdn.co/image/ab67616d0000b2735b57042987606e6f01138b46","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:4WpmwEdc4RBos8W8icSSxW in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:4WpmwEdc4RBos8W8icSSxW Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:3cbV252akVZInSvJk7jAYX in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:3cbV252akVZInSvJk7jAYX Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:0IWtEFQBwRHaMXZQtGEVcM in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:0IWtEFQBwRHaMXZQtGEVcM Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:4ByEFOBuLXpCqvO1kw8Wdm in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:4ByEFOBuLXpCqvO1kw8Wdm Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:1exLL81vN8mD55M9HMOt1t in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:1exLL81vN8mD55M9HMOt1t Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:track:7BdXRaSlGAzhySfuW3y8h5 in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:track:7BdXRaSlGAzhySfuW3y8h5 Jun 16 11:59:56 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreStateMachine::ClearQueue Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreStateMachine::stop Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 11:59:56 volumio2 volumio[1066]: info: CorePlayQueue::clearPlayQueue Jun 16 11:59:56 volumio2 volumio[1066]: info: CorePlayQueue::saveQueue Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPushQueue Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreStateMachine::addQueueItems Jun 16 11:59:56 volumio2 volumio[1066]: info: CorePlayQueue::addQueueItems Jun 16 11:59:56 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 11:59:56 volumio2 volumio[1066]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe Jun 16 11:59:56 volumio2 volumio[1066]: info: Exploding uri spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe in service spop Jun 16 11:59:56 volumio2 volumio[1066]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 11:59:56 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 11:59:56 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 11:59:56 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2aEuA8PSqLa17Y4hKPj5rr","service":"spop","name":"Cheri Cheri Lady","artist":"Modern Talking","album":"Let's Talk About Love","type":"song","duration":226,"albumart":"https://i.scdn.co/image/ab67616d0000b273aedd9728f5cc4b13ee49e061","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6mYrhCAGWzTdF8QnKuchXM","service":"spop","name":"If I Could Turn Back Time","artist":"Cher","album":"Heart Of Stone","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b2737a1e0215c41f0ce411623301","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7BdXRaSlGAzhySfuW3y8h5","service":"spop","name":"She's Like the Wind (feat. Wendy Fraser) - From \"Dirty Dancing\" Soundtrack","artist":"Patrick Swayze","album":"Dirty Dancing (Original Motion Picture Soundtrack)","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b273ac19c6552524d207aac1277b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4WpmwEdc4RBos8W8icSSxW","service":"spop","name":"Moonlight Shadow","artist":"Mike Oldfield","album":"The Mike Oldfield Collection","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b27396a1909790d3b6a986e2b971","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3cbV252akVZInSvJk7jAYX","service":"spop","name":"Flashdance...What a Feeling - Radio Edit","artist":"Irene Cara","album":"What a Feelin'","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b2732ff76b4da68f018b4735ee59","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1exLL81vN8mD55M9HMOt1t","service":"spop","name":"Nothing's Gonna Change My Love For You","artist":"Glenn Medeiros","album":"Nothing's Gonna Change My Love For You","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b273371268198ed8493413f5fe5f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1CtAzw53AIXKjAemxy4b1j","service":"spop","name":"Beds Are Burning - Remastered","artist":"Midnight Oil","album":"Diesel And Dust","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2730dd350beeb5ac73672ad6e80","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4ByEFOBuLXpCqvO1kw8Wdm","service":"spop","name":"(I Just) Died In Your Arms","artist":"Cutting Crew","album":"Broadcast","type":"song","duration":280,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb2faa3ed46d1d0124ca325e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0IWtEFQBwRHaMXZQtGEVcM","service":"spop","name":"Wonderful Life","artist":"Black","album":"Wonderful Life","type":"song","duration":287,"albumart":"https://i.scdn.co/image/ab67616d0000b273a40e4b29bfacc9ef505b86d2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:00 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6QLspHLCLftSGPa6vNzKuo","service":"spop","name":"In The Army Now","artist":"Status Quo","album":"In The Army Now","type":"song","duration":281,"albumart":"https://i.scdn.co/image/ab67616d0000b2733b43ef752e5af1d00c1fc213","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:01 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1aYkkrAbPmMuorVz5HWIqE","service":"spop","name":"The Look","artist":"Roxette","album":"Look Sharp!","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b27322c3c99e7aa0ba6cd08a6be6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPushQueue Jun 16 12:00:02 volumio2 volumio[1066]: info: CorePlayQueue::saveQueue Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::updateTrackBlock Jun 16 12:00:02 volumio2 volumio[1066]: info: CorePlayQueue::getTrackBlock Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPlay Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::play index 0 Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::stop Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::play index undefined Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:02 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:02 volumio2 volumio[1066]: info: CoreStateMachine::startPlaybackTimer Jun 16 12:00:02 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:02 volumio2 volumio[1066]: info: [1750068002957] ControllerSpotify::clearAddPlayTrack Jun 16 12:00:02 volumio2 volumio[1066]: info: Sending Spotify command with payload to local API: /player/play Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=debug msg="resolved context of track" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=trace msg="emitting websocket event: will_play" Jun 16 12:00:03 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:03 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=debug msg="selected format OGG_VORBIS_320 (cc270ca4a539fc7927325b79083ad91bd2a8d03d)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=debug msg="requested aes key for file cc270ca4a539fc7927325b79083ad91bd2a8d03d, gid: 4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:03 volumio2 go-librespot[3665]: time="2025-06-16T12:00:03+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4tcauy2xyIv1q0ckvQmc4H: failed retrieving audio key: failed retrieving aes key with code 1" Jun 16 12:00:03 volumio2 volumio[1066]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Jun 16 12:00:03 volumio2 volumio[1066]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2v7ywbUzCgcVohHaKUcacV","service":"spop","name":"Like a Prayer","artist":"Madonna","album":"Like a Prayer","type":"song","duration":340,"albumart":"https://i.scdn.co/image/ab67616d0000b273fabcc97fd6c3d80fae8d959e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 16 12:00:05 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPlay Jun 16 12:00:05 volumio2 volumio[1066]: info: CoreStateMachine::play index undefined Jun 16 12:00:05 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:05 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:05 volumio2 volumio[1066]: info: CoreStateMachine::startPlaybackTimer Jun 16 12:00:05 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:05 volumio2 volumio[1066]: info: [1750068005559] ControllerSpotify::clearAddPlayTrack Jun 16 12:00:05 volumio2 volumio[1066]: info: Sending Spotify command with payload to local API: /player/play Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=debug msg="resolved context of track" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=trace msg="emitting websocket event: will_play" Jun 16 12:00:05 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:05 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=debug msg="selected format OGG_VORBIS_320 (cc270ca4a539fc7927325b79083ad91bd2a8d03d)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=debug msg="requested aes key for file cc270ca4a539fc7927325b79083ad91bd2a8d03d, gid: 4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:05 volumio2 go-librespot[3665]: time="2025-06-16T12:00:05+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4tcauy2xyIv1q0ckvQmc4H: failed retrieving audio key: failed retrieving aes key with code 1" Jun 16 12:00:05 volumio2 volumio[1066]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Jun 16 12:00:08 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPlay Jun 16 12:00:08 volumio2 volumio[1066]: info: CoreStateMachine::play index undefined Jun 16 12:00:08 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:08 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:08 volumio2 volumio[1066]: info: CoreStateMachine::startPlaybackTimer Jun 16 12:00:08 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:08 volumio2 volumio[1066]: info: [1750068008686] ControllerSpotify::clearAddPlayTrack Jun 16 12:00:08 volumio2 volumio[1066]: info: Sending Spotify command with payload to local API: /player/play Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=debug msg="resolved context of track" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=trace msg="emitting websocket event: will_play" Jun 16 12:00:08 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:08 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=debug msg="selected format OGG_VORBIS_320 (cc270ca4a539fc7927325b79083ad91bd2a8d03d)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=debug msg="requested aes key for file cc270ca4a539fc7927325b79083ad91bd2a8d03d, gid: 4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:08 volumio2 go-librespot[3665]: time="2025-06-16T12:00:08+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4tcauy2xyIv1q0ckvQmc4H: failed retrieving audio key: failed retrieving aes key with code 1" Jun 16 12:00:08 volumio2 volumio[1066]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Jun 16 12:00:17 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::ClearQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::stop Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::clearPlayQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::saveQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPushQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::addQueueItems Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::addQueueItems Jun 16 12:00:17 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 12:00:17 volumio2 volumio[1066]: info: Adding Item to queue: spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe Jun 16 12:00:17 volumio2 volumio[1066]: info: Using cached record of: spotify:user:spotify:playlist:37i9dQZF1DX4UtSsGT1Sbe Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPushQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::saveQueue Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::updateTrackBlock Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrackBlock Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioPlay Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::play index 0 Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::stop Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::play index undefined Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreStateMachine::startPlaybackTimer Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:17 volumio2 volumio[1066]: info: [1750068017366] ControllerSpotify::clearAddPlayTrack Jun 16 12:00:17 volumio2 volumio[1066]: info: Sending Spotify command with payload to local API: /player/play Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=debug msg="resolved context of track" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=trace msg="emitting websocket event: will_play" Jun 16 12:00:17 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:17 volumio2 volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4tcauy2xyIv1q0ckvQmc4H","play_origin":"go-librespot"}} Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=debug msg="selected format OGG_VORBIS_320 (cc270ca4a539fc7927325b79083ad91bd2a8d03d)" uri="spotify:track:4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=debug msg="requested aes key for file cc270ca4a539fc7927325b79083ad91bd2a8d03d, gid: 4tcauy2xyIv1q0ckvQmc4H" Jun 16 12:00:17 volumio2 go-librespot[3665]: time="2025-06-16T12:00:17+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:4tcauy2xyIv1q0ckvQmc4H: failed retrieving audio key: failed retrieving aes key with code 1" Jun 16 12:00:17 volumio2 volumio[1066]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 12:00:17 volumio2 volumio[1066]: info: Discovery: Getting this device information Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::volumioGetState Jun 16 12:00:17 volumio2 volumio[1066]: info: CorePlayQueue::getTrack 0 Jun 16 12:00:17 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 12:00:25 volumio2 go-librespot[3665]: time="2025-06-16T12:00:25+02:00" level=trace msg="sent dealer ping" Jun 16 12:00:25 volumio2 go-librespot[3665]: time="2025-06-16T12:00:25+02:00" level=trace msg="received dealer pong" Jun 16 12:00:28 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 16 12:00:28 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 16 12:00:28 volumio2 volumio[1066]: info: Preload queue cleared Jun 16 12:00:35 volumio2 volumio[1066]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 16 12:00:35 volumio2 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 16 12:00:35 volumio2 dbus-daemon[658]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.54' (uid=0 pid=3791 comm="timedatectl show --property=NTPSynchronized --valu") Jun 16 12:00:35 volumio2 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 16 12:00:36 volumio2 dbus-daemon[658]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 16 12:00:36 volumio2 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 16 12:00:36 volumio2 setdatetime-helper.sh[3790]: Time is not synchronized. Attempting to sync... Jun 16 12:00:36 volumio2 sudo[3799]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Mon, 16 Jun 2025 10:00:36 GMT#015' Jun 16 12:00:36 volumio2 sudo[3799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 16 12:00:36 volumio2 setdatetime-helper.sh[3800]: Mon Jun 16 12:00:36 CEST 2025 Jun 16 12:00:36 volumio2 systemd-journald[367]: Time jumped backwards, rotating. Jun 16 12:00:36 volumio2 sudo[3799]: pam_unix(sudo:session): session closed for user root Jun 16 12:00:36 volumio2 setdatetime-helper.sh[3790]: Time synchronized successfully. Jun 16 12:00:36 volumio2 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 16 12:00:36 volumio2 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 16 12:00:36 volumio2 volumio[1066]: Use XMLElement.setAttribute instead Jun 16 12:00:36 volumio2 volumio[1066]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 12:00:36 volumio2 volumio[1066]: TypeError: children[i].attr(...).value is not a function Jun 16 12:00:36 volumio2 volumio[1066]: at /volumio/app/plugins/music_service/webradio/index.js:428:46 Jun 16 12:00:36 volumio2 volumio[1066]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 16 12:00:36 volumio2 volumio[1066]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 12:00:36 volumio2 sudo[3816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-16 11:59' Jun 16 12:00:36 volumio2 sudo[3816]: 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="ecd46641d85b721d58d1c7edd71dd0a358c8514c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 7 04:21:21 UTC 2025" VOLUMIO_VERSION="4.011" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="97f38114d6fd5ff4ce2816f49b632994"