Sep 06 23:30:00 volumio ntpd[1010]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Sep 06 23:30:00 volumio ntpd[1010]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Sep 06 23:30:00 volumio ntpd[1010]: DNS: Pool skipping: 132.248.30.3 Sep 06 23:30:00 volumio ntpd[1010]: DNS: Pool skipping: 45.134.9.164 Sep 06 23:30:00 volumio ntpd[1010]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Sep 06 23:30:01 volumio ntpd[1010]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Sep 06 23:30:01 volumio ntpd[1010]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool skipping: 192.36.143.130 Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool skipping: 194.0.5.123 Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool skipping: 2a03:8600::cc Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool skipping: 2001:678:8::123 Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool skipping: 2001:19f0:b400:2ffd:5400:5ff:fe63:33ba Sep 06 23:30:01 volumio ntpd[1010]: DNS: Pool taking: 2a03:8600::aa Sep 06 23:30:01 volumio ntpd[1010]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Sep 06 23:30:02 volumio ntpd[1010]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Sep 06 23:30:02 volumio ntpd[1010]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Sep 06 23:30:02 volumio ntpd[1010]: DNS: Pool skipping: 132.248.30.3 Sep 06 23:30:02 volumio ntpd[1010]: DNS: Pool skipping: 194.0.5.123 Sep 06 23:30:02 volumio ntpd[1010]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Sep 06 23:30:02 volumio volumio[1098]: info: CALLMETHOD: music_service soundcloud configSaveGeneralSettings [object Object] Sep 06 23:30:02 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: soundcloud , configSaveGeneralSettings Sep 06 23:30:02 volumio volumio[1098]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 23:30:09 volumio volumio[1098]: info: CALLMETHOD: music_service soundcloud configSavePlaybackSettings [object Object] Sep 06 23:30:09 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: soundcloud , configSavePlaybackSettings Sep 06 23:30:13 volumio volumio[1098]: info: CALLMETHOD: music_service soundcloud configSaveCacheSettings [object Object] Sep 06 23:30:13 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: soundcloud , configSaveCacheSettings Sep 06 23:30:13 volumio volumio[1098]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 23:30:17 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:17 volumio ntpd[1010]: CLOCK: time stepped by -2.279398 Sep 06 23:30:17 volumio ntpd[1010]: INIT: MRU 10922 entries, 13 hash bits, 65536 bytes Sep 06 23:30:17 volumio systemd-journald[513]: Time jumped backwards, rotating. Sep 06 23:30:17 volumio volumio[1098]: info: Executing endpoint metavolumio Sep 06 23:30:17 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 06 23:30:18 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 23:30:18 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 23:30:22 volumio volumio[1098]: info: CoreCommandRouter::volumioGetQueue Sep 06 23:30:22 volumio volumio[1098]: info: CoreStateMachine::getQueue Sep 06 23:30:22 volumio volumio[1098]: info: CorePlayQueue::getQueue Sep 06 23:30:27 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 06 23:30:28 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: soundcloud , handleBrowseUri Sep 06 23:30:28 volumio volumio[1098]: info: [soundcloud] browseUri: soundcloud Sep 06 23:30:29 volumio volumio[1098]: error: [soundcloud] Failed to get top featured tracks in root view: 404 - Not Found FetchError: 404 - Not Found Sep 06 23:30:29 volumio volumio[1098]: at SoundCloud._SoundCloud_validateFetchResponse (/data/plugins/music_service/soundcloud/node_modules/soundcloud-fetch/dist/cjs/lib/SoundCloud.js:402:11) Sep 06 23:30:29 volumio volumio[1098]: at SoundCloud._SoundCloud_fetchEndpoint (/data/plugins/music_service/soundcloud/node_modules/soundcloud-fetch/dist/cjs/lib/SoundCloud.js:379:97) Sep 06 23:30:29 volumio volumio[1098]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Sep 06 23:30:29 volumio volumio[1098]: at async SoundCloud._SoundCloud_fetchCollection (/data/plugins/music_service/soundcloud/node_modules/soundcloud-fetch/dist/cjs/lib/SoundCloud.js:367:18) Sep 06 23:30:29 volumio volumio[1098]: at async Cache.getOrSet (/data/plugins/music_service/soundcloud/dist/lib/util/Cache.js:79:23) Sep 06 23:30:29 volumio volumio[1098]: at async TrackModel._BaseModel_doLoopFetch (/data/plugins/music_service/soundcloud/dist/lib/model/BaseModel.js:111:25) Sep 06 23:30:29 volumio volumio[1098]: at async TrackViewHandler.browse (/data/plugins/music_service/soundcloud/dist/lib/controller/browse/view-handlers/TrackViewHandler.js:48:22) Sep 06 23:30:29 volumio volumio[1098]: at async RootViewHandler._RootViewHandler_getTopFeaturedTracks (/data/plugins/music_service/soundcloud/dist/lib/controller/browse/view-handlers/RootViewHandler.js:144:22) Sep 06 23:30:29 volumio volumio[1098]: at async Promise.all (index 1) Sep 06 23:30:29 volumio volumio[1098]: at async RootViewHandler.browse (/data/plugins/music_service/soundcloud/dist/lib/controller/browse/view-handlers/RootViewHandler.js:29:30) Sep 06 23:30:29 volumio volumio[1098]: at async BrowseController.browseUri (/data/plugins/music_service/soundcloud/dist/lib/controller/browse/BrowseController.js:33:20) Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:31 volumio volumio[1098]: info: Preload queue cleared Sep 06 23:30:44 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:46 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 23:30:46 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 23:30:46 volumio volumio[1098]: info: Executing endpoint metavolumio Sep 06 23:30:46 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 06 23:30:51 volumio volumio[1098]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 23:30:56 volumio volumio[1098]: info: Received OAUTH Data Sep 06 23:30:56 volumio volumio[1098]: info: Executing Spotify Oauth Login Sep 06 23:30:56 volumio volumio[1098]: info: Saving Spotify Refresh Token Sep 06 23:30:57 volumio sudo[4288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 06 23:30:57 volumio sudo[4288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 06 23:30:57 volumio sudo[4288]: pam_unix(sudo:session): session closed for user root Sep 06 23:30:57 volumio sudo[4291]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 06 23:30:57 volumio sudo[4291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: BQCXrFScmiN59zLrtDoxFAAN1wUaqDOi8IOT5RibhhpY4bL2lekVh30pn5QZv3oXA92kv9U38h4GiYrJ4K8CbpkBFht2FaYZByLhxu1jBaKCuMkpEXqTEDaMXVBgGFCm4xyYW3UfgtQgpQsXwnLi7RW3WHxItrbdZmH5MLqmJlEVo4Gb4bG1fnB98LBvg3sP-LQqL3vaf8cXF9nBxfo6QGI59eTGExTXwjou2Ti88bwqcV5FHOw7Y-TKGvihr6y8GN2zoT4cjoIqaS5QO7jZffZGfs9Eb88 Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 23:30:57 volumio volumio[1098]: info: New Spotify access token = BQCXrFScmiN59zLrtDoxFAAN1wUaqDOi8IOT5RibhhpY4bL2lekVh30pn5QZv3oXA92kv9U38h4GiYrJ4K8CbpkBFht2FaYZByLhxu1jBaKCuMkpEXqTEDaMXVBgGFCm4xyYW3UfgtQgpQsXwnLi7RW3WHxItrbdZmH5MLqmJlEVo4Gb4bG1fnB98LBvg3sP-LQqL3vaf8cXF9nBxfo6QGI59eTGExTXwjou2Ti88bwqcV5FHOw7Y-TKGvihr6y8GN2zoT4cjoIqaS5QO7jZffZGfs9Eb88 Sep 06 23:30:57 volumio volumio[1098]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 06 23:30:57 volumio sudo[4291]: pam_unix(sudo:session): session closed for user root Sep 06 23:30:57 volumio volumio[1098]: verbose: New Socket.io Connection to 192.168.100.227 from 192.168.100.117 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::volumioGetVisibleSources Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 06 23:30:57 volumio volumio[1098]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 06 23:30:57 volumio volumio[1098]: info: Received Get System Info Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 23:30:57 volumio volumio[1098]: info: Discovery: Getting this device information Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:57 volumio volumio[1098]: info: Listing playlists Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: User informations: {"country":"MX","display_name":"jesusricardo3","email":"rico_2506@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jesusricardo3"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/jesusricardo3","id":"jesusricardo3","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85e64f804c7c403686d2f0d217","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82e64f804c7c403686d2f0d217","width":64}],"product":"premium","type":"user","uri":"spotify:user:jesusricardo3"} Sep 06 23:30:57 volumio volumio[1098]: info: Creating Spotify config file Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 23:30:57 volumio volumio[1098]: info: Spotify config file written Sep 06 23:30:57 volumio sudo[4298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 06 23:30:57 volumio sudo[4298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 06 23:30:57 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 06 23:30:57 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 06 23:30:57 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 06 23:30:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 06 23:30:57 volumio volumio[1098]: info: Connection to go-librespot Websocket closed Sep 06 23:30:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 06 23:30:57 volumio go-librespot[4303]: go-librespot daemon starting... Sep 06 23:30:57 volumio sudo[4298]: pam_unix(sudo:session): session closed for user root Sep 06 23:30:57 volumio dbus-daemon[758]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.64' (uid=0 pid=4301 comm="timedatectl show --property=NTPSynchronized --valu") Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=info msg="running go-librespot 0.3.2" Sep 06 23:30:57 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="app state loaded" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="stored credentials not found" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 06 23:30:57 volumio dbus-daemon[758]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 06 23:30:57 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 06 23:30:57 volumio setdatetime-helper.sh[4300]: Time is not synchronized. Attempting to sync... Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=info msg="zeroconf server listening on port 43737" Sep 06 23:30:57 volumio sudo[4317]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sun, 07 Sep 2025 05:30:57 GMT#015' Sep 06 23:30:57 volumio sudo[4317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 06 23:30:57 volumio setdatetime-helper.sh[4318]: Sat Sep 6 23:30:57 CST 2025 Sep 06 23:30:57 volumio systemd-journald[513]: Time jumped backwards, rotating. Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: BQACYkFDYTKWetRKjFzdnG76e-uJV5r_B96c-1yYCFtwjzYP-s1wi9rhP-FUG5trwYMNUh02aWUEoDrLUk6GgiiaOjA-Y2JDV0_YNJv9FGoT1r5sXtVKUCDG6lK8pvc_fqg3Vw1IFKKdjI332L8q8IEnxui21HbuR-w3AeK51NaLdvblnpsPhKBagGflXiy5HGxso8NA29JKPOKeq7oV73Z4zmX483t8CNK8Q4wnl2-ZGuOPUU0cVgSuF9nKXJfPwSaCJ7CeY8g1DqwCBe2xt44f5DyI0RM Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 23:30:57 volumio volumio[1098]: info: New Spotify access token = BQACYkFDYTKWetRKjFzdnG76e-uJV5r_B96c-1yYCFtwjzYP-s1wi9rhP-FUG5trwYMNUh02aWUEoDrLUk6GgiiaOjA-Y2JDV0_YNJv9FGoT1r5sXtVKUCDG6lK8pvc_fqg3Vw1IFKKdjI332L8q8IEnxui21HbuR-w3AeK51NaLdvblnpsPhKBagGflXiy5HGxso8NA29JKPOKeq7oV73Z4zmX483t8CNK8Q4wnl2-ZGuOPUU0cVgSuF9nKXJfPwSaCJ7CeY8g1DqwCBe2xt44f5DyI0RM Sep 06 23:30:57 volumio volumio[1098]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 06 23:30:57 volumio setdatetime-helper.sh[4300]: Time synchronized successfully. Sep 06 23:30:57 volumio sudo[4317]: pam_unix(sudo:session): session closed for user root Sep 06 23:30:57 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 06 23:30:57 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="obtained new client token: AAC9TtrWwMr14CxbLb3IMBYWo6PLHp6oz7YuNHkFTuU1dqIlHMaSY9hcQW6tpaf6ORXkyj6trefsOOthQifZ75mW9GuMQhDLstQgr4JJFaOdMHzVWrCVTJ6XFnZuR8nlAwuHk1IW5B19UgRMUWl5cescKpbL3ZJgcs+4K1fhB7KkO9oPag4RdfJcmeMVCpoYgOvtazpTbaBhKFOjEDmuZfzVrJjvzcL0+tg6KYVFv3PE3aFKWRAEv8iG" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Sep 06 23:30:57 volumio volumio[1098]: SPOTIFY: User informations: {"country":"MX","display_name":"jesusricardo3","email":"rico_2506@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/jesusricardo3"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/jesusricardo3","id":"jesusricardo3","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85e64f804c7c403686d2f0d217","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82e64f804c7c403686d2f0d217","width":64}],"product":"premium","type":"user","uri":"spotify:user:jesusricardo3"} Sep 06 23:30:57 volumio volumio[1098]: info: Spotify Successfully logged in Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 06 23:30:57 volumio volumio[1098]: info: [1757223057210] CoreMusicLibrary::Adding element Spotify Sep 06 23:30:57 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source HD-Audio Generic Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source 80s80s Radio Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source Podcast Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source SoundCloud Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source YouTube2 Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source YouTube Music Sep 06 23:30:57 volumio volumio[1098]: Cannot find translation for source Spotify Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="completed keyexchange" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="completed challenge" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=info msg="authenticated AP" username="je*********o3" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=info msg="authenticated Login5" username="je*********o3" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="stored credentials" username="je*********o3" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="initializing zeroconf session" username="je*********o3" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="dealer connection opened" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=trace msg="starting accesspoint recv loop" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=trace msg="starting dealer recv loop" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=trace msg="received accesspoint ping" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="received connection id: NzNkNWEzN2ItNTFi...ODBFRUY4RTAxMg==" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=trace msg="received accesspoint pong ack" Sep 06 23:30:57 volumio go-librespot[4304]: time="2025-09-06T23:30:57-06:00" level=debug msg="put connect state because NEW_DEVICE" Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 23:30:58 volumio volumio[1098]: info: Received Get System Info Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 23:30:58 volumio volumio[1098]: info: Discovery: Getting this device information Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:58 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 23:30:59 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 23:30:59 volumio volumio[1098]: info: Received Get System Info Sep 06 23:30:59 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 23:30:59 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 23:30:59 volumio volumio[1098]: info: Discovery: Getting this device information Sep 06 23:30:59 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:30:59 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 23:30:59 volumio volumio[1098]: info: Initializing connection to go-librespot Websocket Sep 06 23:30:59 volumio go-librespot[4304]: time="2025-09-06T23:30:59-06:00" level=debug msg="new websocket client" Sep 06 23:30:59 volumio volumio[1098]: info: Connection to go-librespot Websocket established Sep 06 23:30:59 volumio volumio[1098]: info: go-librespot daemon successfully initialized Sep 06 23:31:02 volumio volumio[1098]: info: Getting Spotify volume Sep 06 23:31:02 volumio volumio[1098]: info: Spotify volume: 100 Sep 06 23:31:02 volumio volumio[1098]: info: Initializing connection to go-librespot Websocket Sep 06 23:31:02 volumio volumio[1098]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 06 23:31:02 volumio go-librespot[4304]: time="2025-09-06T23:31:02-06:00" level=debug msg="new websocket client" Sep 06 23:31:02 volumio volumio[1098]: info: Connection to go-librespot Websocket established Sep 06 23:31:02 volumio volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 06 23:31:02 volumio volumio[1098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 23:31:05 volumio volumio[1098]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Sep 06 23:31:05 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Sep 06 23:31:05 volumio volumio[1098]: info: Creating Spotify config file Sep 06 23:31:05 volumio volumio[1098]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 23:31:05 volumio volumio[1098]: info: Spotify config file written Sep 06 23:31:05 volumio sudo[4344]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 06 23:31:05 volumio sudo[4344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 06 23:31:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 06 23:31:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 06 23:31:05 volumio volumio[1098]: info: Connection to go-librespot Websocket closed Sep 06 23:31:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 06 23:31:05 volumio volumio[1098]: info: Connection to go-librespot Websocket closed Sep 06 23:31:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 06 23:31:05 volumio go-librespot[4346]: go-librespot daemon starting... Sep 06 23:31:05 volumio sudo[4344]: pam_unix(sudo:session): session closed for user root Sep 06 23:31:05 volumio volumio[1098]: info: Getting Spotify volume Sep 06 23:31:05 volumio volumio[1098]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=info msg="running go-librespot 0.3.2" Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=debug msg="app state loaded" Sep 06 23:31:05 volumio volumio[1098]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 06 23:31:05 volumio volumio[1098]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 06 23:31:05 volumio volumio[1098]: errno: -111, Sep 06 23:31:05 volumio volumio[1098]: code: 'ECONNREFUSED', Sep 06 23:31:05 volumio volumio[1098]: syscall: 'connect', Sep 06 23:31:05 volumio volumio[1098]: address: '127.0.0.1', Sep 06 23:31:05 volumio volumio[1098]: port: 9879, Sep 06 23:31:05 volumio volumio[1098]: response: undefined Sep 06 23:31:05 volumio volumio[1098]: } Sep 06 23:31:05 volumio volumio[1098]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 06 23:31:05 volumio sudo[4369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-06 23:30' Sep 06 23:31:05 volumio sudo[4369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 06 23:31:05 volumio go-librespot[4347]: time="2025-09-06T23:31:05-06:00" level=info msg="zeroconf server listening on port 43259" PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="477d19cd2b4ebf4b4c802be78e00bbb657e83aea" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Aug 2 17:12:12 UTC 2025" VOLUMIO_VERSION="4.021" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="929ec80ad6e74b38757fdba2e7d66ff0"