Dec 29 10:42:00 pcstreameraudiotech volumio[1199]: info: Checking if install.sh is present Dec 29 10:42:00 pcstreameraudiotech volumio[1199]: info: Executing install.sh Dec 29 10:42:00 pcstreameraudiotech sudo[4127]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Dec 29 10:42:00 pcstreameraudiotech sudo[4127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:42:00 pcstreameraudiotech volumio[1199]: info: Installing Go-librespot Dec 29 10:42:00 pcstreameraudiotech volumio[1199]: info: Checking old vollibrespot installs Dec 29 10:42:00 pcstreameraudiotech systemd[1]: Reloading. Dec 29 10:42:01 pcstreameraudiotech volumio[1199]: info: Downloading daemon Dec 29 10:42:02 pcstreameraudiotech volumio[1199]: info: Creating directories Dec 29 10:42:02 pcstreameraudiotech volumio[1199]: info: Creating data directory Dec 29 10:42:02 pcstreameraudiotech volumio[1199]: info: Creating Start Script Dec 29 10:42:04 pcstreameraudiotech systemd[1]: Reloading. Dec 29 10:42:04 pcstreameraudiotech sudo[4127]: pam_unix(sudo:session): session closed for user root Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: Plugin install end detected on script Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Install script completed Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Adding reference to registry Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Done installing plugin. Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Folder /tmp/plugins removed Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Folder /tmp/downloaded_plugin.zip removed Dec 29 10:42:04 pcstreameraudiotech volumio[1199]: info: Folder /data/temp removed Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: Enabling plugin spop Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: Loading plugin "spop"... Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: PLUGIN START: spop Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: Done. Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:42:13 pcstreameraudiotech sudo[4213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:42:13 pcstreameraudiotech sudo[4213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:42:13 pcstreameraudiotech volumio[1199]: info: No need to fix Spotify hosts Dec 29 10:42:13 pcstreameraudiotech systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 29 10:42:13 pcstreameraudiotech systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 29 10:42:14 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:42:14 pcstreameraudiotech go-librespot[4215]: go-librespot daemon starting... Dec 29 10:42:14 pcstreameraudiotech sudo[4213]: pam_unix(sudo:session): session closed for user root Dec 29 10:42:14 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:14-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:42:14 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:14-05:00" level=debug msg="no app state found" Dec 29 10:42:14 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:14-05:00" level=debug msg="stored credentials not found" Dec 29 10:42:14 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:14-05:00" level=info msg="generated new device id: 330e23559cb8a1d5e54278b738d8d6fcd3149721" Dec 29 10:42:14 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:42:17 pcstreameraudiotech volumio[1199]: info: go-librespot daemon successfully initialized Dec 29 10:42:19 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:19-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 29 10:42:19 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:19-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 29 10:42:19 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:19-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 29 10:42:19 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:19-05:00" level=info msg="zeroconf server listening on port 43887" Dec 29 10:42:20 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:42:20 pcstreameraudiotech go-librespot[4216]: time="2025-12-29T10:42:20-05:00" level=debug msg="new websocket client" Dec 29 10:42:20 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:42:20 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: SPOTIFY: SPOTIFY VOLUME undefined Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: SPOTIFY: VOLUMIO VOLUME 41 Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: Aligning Spotify Volume to Volumio Volume Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:42:23 pcstreameraudiotech volumio[1199]: info: Setting Spotify Volume from Volumio: 41 Dec 29 10:42:24 pcstreameraudiotech sudo[4276]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 10:42:24 pcstreameraudiotech sudo[4276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:42:24 pcstreameraudiotech sudo[4278]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 10:42:24 pcstreameraudiotech sudo[4278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:42:24 pcstreameraudiotech sudo[4276]: pam_unix(sudo:session): session closed for user root Dec 29 10:42:24 pcstreameraudiotech sudo[4278]: pam_unix(sudo:session): session closed for user root Dec 29 10:42:24 pcstreameraudiotech volumio[1199]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Dec 29 10:42:24 pcstreameraudiotech volumio[1199]: info: Sending Spotify command with payload to local API: /player/volume Dec 29 10:43:10 pcstreameraudiotech volumio[1199]: info: Received OAUTH Data Dec 29 10:43:10 pcstreameraudiotech volumio[1199]: info: Executing Spotify Oauth Login Dec 29 10:43:10 pcstreameraudiotech volumio[1199]: info: Saving Spotify Refresh Token Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: BQCiBURTDZm4y6r64XtJsyBIccRDPOoCL0BKSX3fCXEJaLVxOz8q-eElgDi5fsNSgIIacwJpNStCMZcLrZRwxgHnC-nAY5LYGy304ClXZc6Gvyjek8JHUOccNz7zJPK1ivYJceJqmpfkrVTpD2fSE0TLeFCH4Xpp_QXucsgXI-N8rnnADlE_aOeMPrZxZNk3hhu8PpsAvkFpL69dNojkH-3Zmn1LRDV3Pq6bXIoi5KPK2OrelhlT4uTz75XiYDMliFwm8Kh_VqJ_PkqGVPxG4EySqq10Uh9GPnEIJSmyCsTJV1fQNWL97Cec Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: New Spotify access token = BQCiBURTDZm4y6r64XtJsyBIccRDPOoCL0BKSX3fCXEJaLVxOz8q-eElgDi5fsNSgIIacwJpNStCMZcLrZRwxgHnC-nAY5LYGy304ClXZc6Gvyjek8JHUOccNz7zJPK1ivYJceJqmpfkrVTpD2fSE0TLeFCH4Xpp_QXucsgXI-N8rnnADlE_aOeMPrZxZNk3hhu8PpsAvkFpL69dNojkH-3Zmn1LRDV3Pq6bXIoi5KPK2OrelhlT4uTz75XiYDMliFwm8Kh_VqJ_PkqGVPxG4EySqq10Uh9GPnEIJSmyCsTJV1fQNWL97Cec Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: User informations: {"country":"CA","display_name":"Daniel Goupil","email":"piliel@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/22wpywcwx6wey5i4bk6dup2kq"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/22wpywcwx6wey5i4bk6dup2kq","id":"22wpywcwx6wey5i4bk6dup2kq","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10154254678804840&height=300&width=300&ext=1769610359&hash=AT9rmX_zlxjfYp7zhRgnbt6S","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10154254678804840&height=50&width=50&ext=1769610359&hash=AT-pcCmC9KzsfX0TSDTMKBW0","width":64}],"product":"premium","type":"user","uri":"spotify:user:22wpywcwx6wey5i4bk6dup2kq"} Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:43:11 pcstreameraudiotech sudo[4410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:43:11 pcstreameraudiotech sudo[4410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:11 pcstreameraudiotech systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:11 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 29 10:43:11 pcstreameraudiotech systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:11 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:11 pcstreameraudiotech go-librespot[4412]: go-librespot daemon starting... Dec 29 10:43:11 pcstreameraudiotech sudo[4410]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="app state loaded" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="stored credentials not found" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:43:11 pcstreameraudiotech sudo[4421]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 29 10:43:11 pcstreameraudiotech sudo[4421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:11 pcstreameraudiotech sudo[4423]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 29 10:43:11 pcstreameraudiotech sudo[4423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:11 pcstreameraudiotech sudo[4421]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:11 pcstreameraudiotech sudo[4423]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=info msg="zeroconf server listening on port 37809" Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to 192.168.2.126 from 192.168.2.122 UA: Mozilla/5.0 (Android 13; Mobile; rv:146.0) Gecko/146.0 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 6 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: BQAWmXFxuLguBWCduJXRUDxa3tGj_Xpdf1hZEIzvtrdhUnJD2Y21bf7mog9SsHXHMjwKfeC_cd5jMyvgdDvM1krUx-WImZlOfaYoS6j6A7bRx3LuE7WpgYyxqsFoysTvdA8VLRmEqmhKdYTtCEycw1bfqrVYlxdyvHIYtATyXaUXVh9a-IpLytwPyPCzRi-UNSuStlKtZIAqsj1dSQzPoUhvL2q5727o6kERFBoSbQSMkiLfX9p-bLVseVu0elqlQnEkeo3W9P80AjxYtDPXrDlmGuflJdhUgDvYO8Uc3r9di8BnljRPkh4G Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: New Spotify access token = BQAWmXFxuLguBWCduJXRUDxa3tGj_Xpdf1hZEIzvtrdhUnJD2Y21bf7mog9SsHXHMjwKfeC_cd5jMyvgdDvM1krUx-WImZlOfaYoS6j6A7bRx3LuE7WpgYyxqsFoysTvdA8VLRmEqmhKdYTtCEycw1bfqrVYlxdyvHIYtATyXaUXVh9a-IpLytwPyPCzRi-UNSuStlKtZIAqsj1dSQzPoUhvL2q5727o6kERFBoSbQSMkiLfX9p-bLVseVu0elqlQnEkeo3W9P80AjxYtDPXrDlmGuflJdhUgDvYO8Uc3r9di8BnljRPkh4G Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: SPOTIFY: User informations: {"country":"CA","display_name":"Daniel Goupil","email":"piliel@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/22wpywcwx6wey5i4bk6dup2kq"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/22wpywcwx6wey5i4bk6dup2kq","id":"22wpywcwx6wey5i4bk6dup2kq","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10154254678804840&height=300&width=300&ext=1769610359&hash=AT9rmX_zlxjfYp7zhRgnbt6S","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10154254678804840&height=50&width=50&ext=1769610359&hash=AT-pcCmC9KzsfX0TSDTMKBW0","width":64}],"product":"premium","type":"user","uri":"spotify:user:22wpywcwx6wey5i4bk6dup2kq"} Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Spotify Successfully logged in Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: [1767022991574] CoreMusicLibrary::Adding element Spotify Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: Cannot find translation for source Spotify Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="obtained new client token: AAAkgD/DbrP+r1jumSAZi7m27G/x9S6V0r6l5M+PzR6l81yIaXiB9XEAJjaS6Jd+WlIG91ctOECmUxS8NH2ZIhFFCfFwPoIs/vkSZknM41ab924aX2Wqv7PPErmG1F5nJqT/iGo+07ZOZh1OwBmCGvbP7O1JCxyPD/TB5bEfO3iCoS7QQnEkPj0dBmoA0TdQSwJ2LcP/w2aGpGgbQvYvIn7mJ+mHeuC+SJ6URU/L4ZtsbLBEjwSHAr2MAw==" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetVisibleSources Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Received Get System Info Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Discovery: Getting this device information Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: Listing playlists Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 29 10:43:11 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="completed keyexchange" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=debug msg="completed challenge" Dec 29 10:43:11 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:11-05:00" level=info msg="authenticated AP" username="22*********************kq" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=info msg="authenticated Login5" username="22*********************kq" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="stored credentials" username="22*********************kq" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="initializing zeroconf session" username="22*********************kq" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="dealer connection opened" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=trace msg="starting accesspoint recv loop" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=trace msg="starting dealer recv loop" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=trace msg="received accesspoint ping" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="received connection id: MmYxMWFmYzAtODYx...QzlCRjYyNTkyQg==" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=trace msg="received accesspoint pong ack" Dec 29 10:43:12 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:12-05:00" level=debug msg="put connect state because NEW_DEVICE" Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: Received Get System Info Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: Discovery: Getting this device information Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 10:43:13 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 29 10:43:14 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:43:14 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:14-05:00" level=debug msg="new websocket client" Dec 29 10:43:14 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:43:14 pcstreameraudiotech volumio[1199]: info: go-librespot daemon successfully initialized Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: Received Get System Info Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: Discovery: Getting this device information Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:16 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: Spotify volume: 100 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: SPOTIFY: SPOTIFY VOLUME 100 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: SPOTIFY: VOLUMIO VOLUME 41 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: Setting Spotify Volume from Volumio: 41 Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:43:17 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:17-05:00" level=debug msg="new websocket client" Dec 29 10:43:17 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:43:18 pcstreameraudiotech volumio[1199]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Dec 29 10:43:18 pcstreameraudiotech volumio[1199]: info: Sending Spotify command with payload to local API: /player/volume Dec 29 10:43:18 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:18-05:00" level=debug msg="update volume requested to 26869/65535" Dec 29 10:43:19 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:19-05:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 29 10:43:19 pcstreameraudiotech go-librespot[4413]: time="2025-12-29T10:43:19-05:00" level=trace msg="emitting websocket event: volume" Dec 29 10:43:19 pcstreameraudiotech volumio[1199]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Dec 29 10:43:19 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Dec 29 10:43:19 pcstreameraudiotech volumio[1199]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Dec 29 10:43:19 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: info: Spotify volume: 41 Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:20 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:43:21 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 29 10:43:24 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::Close All Modals sent Dec 29 10:43:24 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: appearance , setTOSAccepted Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: Received Get System Version Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: Received Get System Info Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: Discovery: Getting this device information Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:30 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:43:32 pcstreameraudiotech sudo[4490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:43:32 pcstreameraudiotech sudo[4490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:32 pcstreameraudiotech systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 29 10:43:32 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Killing process 4428 (go-librespot) with signal SIGKILL. Dec 29 10:43:32 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 29 10:43:32 pcstreameraudiotech systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:32 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:32 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:32 pcstreameraudiotech sudo[4490]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:32 pcstreameraudiotech go-librespot[4492]: go-librespot daemon starting... Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="app state loaded" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=info msg="zeroconf server listening on port 34835" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="obtained new client token: AAAjNwTxhU6I7MZ1c0HJevBDWCoq5xgZaB9Ko4BELeOGazle9Dwe9NddrJxFYuO5IQhbCTU4dvHgMuHg2oe0oXseB31kL4/dDFIWEimqW5m2rbxm6gFdWrX8id5zXgbu3mkEuTnj80Ct19ycr1RXkSB7AeMiyLqNyo7PYRdXHXtrD0lT250KSKRJeWOHI7kokzOcD7HXKO7TMhP30uEKFsXRErHR+17THxnzTG8+xEU/txkk/DlZ0WbDbA==" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="completed keyexchange" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="completed challenge" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=info msg="authenticated AP" username="22*********************kq" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=info msg="authenticated Login5" username="22*********************kq" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="initializing zeroconf session" username="22*********************kq" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="dealer connection opened" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=trace msg="starting accesspoint recv loop" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=trace msg="starting dealer recv loop" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=trace msg="received accesspoint ping" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=debug msg="received connection id: NDkxOGMzMDgtN2M2...MTEwRDdCMTc3MQ==" Dec 29 10:43:32 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:32-05:00" level=trace msg="received accesspoint pong ack" Dec 29 10:43:33 pcstreameraudiotech go-librespot[4493]: time="2025-12-29T10:43:33-05:00" level=debug msg="put connect state because NEW_DEVICE" Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:43:35 pcstreameraudiotech sudo[4518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:43:35 pcstreameraudiotech sudo[4518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:35 pcstreameraudiotech systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 29 10:43:35 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 29 10:43:35 pcstreameraudiotech systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:35 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:35 pcstreameraudiotech sudo[4518]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:35 pcstreameraudiotech go-librespot[4520]: go-librespot daemon starting... Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="app state loaded" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="new websocket client" Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:43:35 pcstreameraudiotech volumio[1199]: info: go-librespot daemon successfully initialized Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=info msg="zeroconf server listening on port 35447" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="obtained new client token: AADVZkAQGq7ULUjO59rTzx2gXiElxCpgu3f9L1t85FlgyqFpRSWr18R/sdWKY4OjqdNxXrK1RWD0T4jM9ZXyloCCzat2R8xWiuD+0nfQ05XqKah8PbpV19EWi/2WpjQAHN0q7I2YV+d9BwxvVaFVGvHlAdSKdIHiF9uguRoNZ0WCZ0VQzJL2sHLXCRCbPe1YNHBhkVC577ZZNEpp/BjsGsKxCIGeT5sI6m4tw1yAXbzV37CmXKosKDcNxw==" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="completed keyexchange" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="completed challenge" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=info msg="authenticated AP" username="22*********************kq" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=info msg="authenticated Login5" username="22*********************kq" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="initializing zeroconf session" username="22*********************kq" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="dealer connection opened" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=trace msg="starting accesspoint recv loop" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=trace msg="starting dealer recv loop" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=trace msg="received accesspoint ping" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 29 10:43:35 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:35-05:00" level=debug msg="received connection id: ZDRmYjhjMGQtZmFk...MDUzODc1QTY4Qg==" Dec 29 10:43:36 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:36-05:00" level=trace msg="received accesspoint pong ack" Dec 29 10:43:36 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:36-05:00" level=debug msg="put connect state because NEW_DEVICE" Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: go-librespot daemon successfully initialized Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: Spotify volume: 100 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: SPOTIFY: SPOTIFY VOLUME 100 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: SPOTIFY: VOLUMIO VOLUME 41 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: Setting Spotify Volume from Volumio: 41 Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:43:38 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:38-05:00" level=debug msg="new websocket client" Dec 29 10:43:38 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:43:39 pcstreameraudiotech volumio[1199]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Dec 29 10:43:39 pcstreameraudiotech volumio[1199]: info: Sending Spotify command with payload to local API: /player/volume Dec 29 10:43:39 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:39-05:00" level=debug msg="update volume requested to 26869/65535" Dec 29 10:43:40 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:40-05:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 29 10:43:40 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:40-05:00" level=trace msg="emitting websocket event: volume" Dec 29 10:43:40 pcstreameraudiotech volumio[1199]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Dec 29 10:43:40 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Dec 29 10:43:40 pcstreameraudiotech volumio[1199]: SPOTIFY: received: {"type":"volume","data":{"value":41,"max":100}} Dec 29 10:43:40 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED SPOTIFY VOLUME 41 Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: Initializing connection to go-librespot Websocket Dec 29 10:43:41 pcstreameraudiotech go-librespot[4521]: time="2025-12-29T10:43:41-05:00" level=debug msg="new websocket client" Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket established Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: Spotify volume: 41 Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:41 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:43:43 pcstreameraudiotech sudo[4541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:43:43 pcstreameraudiotech sudo[4541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:43 pcstreameraudiotech systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 29 10:43:43 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Killing process 4528 (go-librespot) with signal SIGKILL. Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:43 pcstreameraudiotech volumio[1199]: info: Connection to go-librespot Websocket closed Dec 29 10:43:43 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 29 10:43:43 pcstreameraudiotech systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:43 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:43 pcstreameraudiotech sudo[4541]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:43 pcstreameraudiotech go-librespot[4543]: go-librespot daemon starting... Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="app state loaded" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=info msg="zeroconf server listening on port 40821" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="obtained new client token: AAAOZlg3vlXj/smwqkvh0ep/nIjnQmp3Ijc4KCnDfvV2fpSCwgdT87z/LAUSTRSn7xAMrZFPiY3WZo2F7mc0rJrW7T+ApQpK1ijbnLfrgCsLKy+Zd2mdPLP7/u+QLZqWsZ4UvyQ4yrZRwA7vkWJXtJjSPYy87WhE+0wxVedispjXamStPT49RQRICPUO4XOXWpxW/iAe+5meNIK1IWdIRhOg7uTaKXh0mZ8oTqQEMgDzyHdhoA0YTj3x7A==" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="completed keyexchange" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=debug msg="completed challenge" Dec 29 10:43:43 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:43-05:00" level=info msg="authenticated AP" username="22*********************kq" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=info msg="authenticated Login5" username="22*********************kq" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="initializing zeroconf session" username="22*********************kq" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="dealer connection opened" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=trace msg="starting accesspoint recv loop" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=trace msg="starting dealer recv loop" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=trace msg="received accesspoint ping" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=debug msg="received connection id: NGE4NDhlODktMDI3...NkVBMTFCNDBEMA==" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4544]: time="2025-12-29T10:43:44-05:00" level=trace msg="received accesspoint pong ack" Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: Getting Spotify volume Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::volumioGetState Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: CorePlayQueue::getTrack 0 Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: Creating Spotify config file Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: info: Spotify config file written Dec 29 10:43:44 pcstreameraudiotech sudo[4567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 29 10:43:44 pcstreameraudiotech sudo[4567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 29 10:43:44 pcstreameraudiotech systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 29 10:43:44 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Killing process 4550 (go-librespot) with signal SIGKILL. Dec 29 10:43:44 pcstreameraudiotech systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 29 10:43:44 pcstreameraudiotech systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: Error: socket hang up Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: at connResetException (node:internal/errors:720:14) Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: at Socket.emit (node:events:526:35) Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: code: 'ECONNRESET', Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: response: undefined Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: } Dec 29 10:43:44 pcstreameraudiotech volumio[1199]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 29 10:43:44 pcstreameraudiotech systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 29 10:43:44 pcstreameraudiotech go-librespot[4569]: go-librespot daemon starting... Dec 29 10:43:44 pcstreameraudiotech sudo[4567]: pam_unix(sudo:session): session closed for user root Dec 29 10:43:44 pcstreameraudiotech go-librespot[4582]: time="2025-12-29T10:43:44-05:00" level=info msg="running go-librespot 0.4.0" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4582]: time="2025-12-29T10:43:44-05:00" level=debug msg="app state loaded" Dec 29 10:43:44 pcstreameraudiotech go-librespot[4582]: time="2025-12-29T10:43:44-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 29 10:43:44 pcstreameraudiotech sudo[4590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-29 10:42' Dec 29 10:43:44 pcstreameraudiotech sudo[4590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 21:07:15 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4b5c74f40f473b90a542bf010b97924b"