-- Logs begin at Tue 2025-05-06 09:23:37 CEST, end at Thu 2025-05-08 19:47:46 CEST. -- May 08 19:46:01 volumio-wk volumio[755]: info: Loading plugin "upnp_browser"... May 08 19:46:04 volumio-wk volumio[755]: info: Loading plugin "alarm-clock"... May 08 19:46:06 volumio-wk volumio[755]: info: Loading plugin "airplay_emulation"... May 08 19:46:06 volumio-wk volumio[755]: info: Starting Shairport Sync May 08 19:46:06 volumio-wk volumio[755]: info: Loading plugin "last_100"... May 08 19:46:06 volumio-wk volumio[755]: info: Loading plugin "webradio"... May 08 19:46:07 volumio-wk volumio[755]: info: Loading plugin "i2s_dacs"... May 08 19:46:07 volumio-wk volumio[755]: info: Loading plugin "volumiodiscovery"... May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** For more information see May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 19:46:07 volumio-wk volumio[755]: *** WARNING *** For more information see May 08 19:46:07 volumio-wk node[755]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 19:46:07 volumio-wk node[755]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 19:46:07 volumio-wk node[755]: *** WARNING *** For more information see May 08 19:46:07 volumio-wk node[755]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 19:46:07 volumio-wk node[755]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 19:46:07 volumio-wk node[755]: *** WARNING *** For more information see May 08 19:46:07 volumio-wk volumio[755]: info: Applying required configuration parameters for plugin volumiodiscovery May 08 19:46:07 volumio-wk volumio[755]: info: Discovery: Started advertising with name: Volumio-wk May 08 19:46:07 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 19:46:07 volumio-wk volumio[755]: info: Loading plugin "spop"... May 08 19:46:09 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:46:09] [connect] Successful connection May 08 19:46:16 volumio-wk volumio[755]: info: Loading plugin "outputs"... May 08 19:46:16 volumio-wk volumio[755]: info: Loading plugin "albumart"... May 08 19:46:17 volumio-wk volumio[755]: info: Plugin example_plugin is not enabled May 08 19:46:17 volumio-wk volumio[755]: info: Loading plugin "inputs"... May 08 19:46:17 volumio-wk volumio[755]: info: Loading plugin "updater_comm"... May 08 19:46:20 volumio-wk volumio[755]: info: Plugin mpdemulation is not enabled May 08 19:46:20 volumio-wk volumio[755]: info: Loading plugin "rest_api"... May 08 19:46:21 volumio-wk volumio[755]: info: Loading plugin "websocket"... May 08 19:46:21 volumio-wk volumio[755]: info: Starting Socket.io Server version 2.3.0 May 08 19:46:21 volumio-wk volumio[755]: info: Loading i18n strings for locale nl May 08 19:46:21 volumio-wk volumio[755]: Updating browse sources language May 08 19:46:21 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 19:46:22 volumio-wk volumio[755]: Forking 1 albumart workers May 08 19:46:23 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 19:46:23 volumio-wk volumio[755]: info: CoreCommandRouter::initPlayerControls May 08 19:46:24 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:24 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:24 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:24 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 19:46:24 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:46:24] [connect] Successful connection May 08 19:46:24 volumio-wk volumio[755]: Express server listening on port 3000 May 08 19:46:24 volumio-wk volumio[755]: [Metrics] WebUI: 46s 248.97ms May 08 19:46:24 volumio-wk volumio[755]: info: CoreStateMachine::resetVolumioState May 08 19:46:24 volumio-wk volumio[755]: info: CoreStateMachine::getcurrentVolume May 08 19:46:24 volumio-wk volumio[755]: info: CoreCommandRouter::volumioRetrievevolume May 08 19:46:25 volumio-wk sudo[998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 19:46:25 volumio-wk sudo[998]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:25 volumio-wk sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 19:46:25 volumio-wk sudo[998]: pam_unix(sudo:session): session closed for user root May 08 19:46:25 volumio-wk sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:25 volumio-wk sudo[1000]: pam_unix(sudo:session): session closed for user root May 08 19:46:25 volumio-wk volumio[755]: info: Volumio Network Manager: Network status updated: 1 May 08 19:46:26 volumio-wk volumio[755]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 08 19:46:26 volumio-wk volumio[755]: wlan0 Interface doesn't support scanning. May 08 19:46:26 volumio-wk volumio[755]: info: Cannot use regular scanning, forcing with ap-force May 08 19:46:26 volumio-wk sudo[1006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 08 19:46:26 volumio-wk sudo[1006]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:26 volumio-wk sudo[1006]: pam_unix(sudo:session): session closed for user root May 08 19:46:26 volumio-wk volumio[755]: command failed: No such device (-19) May 08 19:46:26 volumio-wk volumio[755]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 08 19:46:26 volumio-wk volumio[755]: command failed: No such device (-19) May 08 19:46:28 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:46:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746726384 101 May 08 19:46:28 volumio-wk volumio[755]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 May 08 19:46:28 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 19:46:29 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:29 volumio-wk volumio[755]: info: Reloading queue from file May 08 19:46:29 volumio-wk volumio[755]: info: VolumeController:: Volume=84 Mute =false May 08 19:46:29 volumio-wk volumio[755]: info: CoreStateMachine::pushState May 08 19:46:29 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:29 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 19:46:29 volumio-wk volumio[755]: info: CoreCommandRouter::volumioPushState May 08 19:46:29 volumio-wk volumio[755]: info: CoreStateMachine::updateTrackBlock May 08 19:46:29 volumio-wk volumio[755]: info: CorePlayQueue::getTrackBlock May 08 19:46:29 volumio-wk volumio[755]: info: CoreCommandRouter::volumioRetrievevolume May 08 19:46:30 volumio-wk volumio[755]: info: CoreStateMachine::setRepeat null single undefined May 08 19:46:30 volumio-wk volumio[755]: info: CoreStateMachine::pushState May 08 19:46:30 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:30 volumio-wk volumio[755]: info: CoreCommandRouter::volumioPushState May 08 19:46:30 volumio-wk volumio[755]: info: CoreStateMachine::setRandom null May 08 19:46:30 volumio-wk volumio[755]: info: CoreStateMachine::pushState May 08 19:46:30 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:30 volumio-wk volumio[755]: info: CoreCommandRouter::volumioPushState May 08 19:46:30 volumio-wk volumio[755]: info: Setting Device type: Raspberry PI May 08 19:46:30 volumio-wk volumio[755]: info: Completed loading Core Plugins May 08 19:46:30 volumio-wk volumio[755]: info: Preparing to generate the ALSA configuration file May 08 19:46:31 volumio-wk volumio[755]: info: Asound.conf file unchanged, so no further update is needed May 08 19:46:31 volumio-wk volumio[755]: info: Output device has changed, restarting MPD May 08 19:46:31 volumio-wk sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 08 19:46:31 volumio-wk sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:31 volumio-wk systemd[1]: Started UPnP Renderer front-end to MPD. May 08 19:46:31 volumio-wk volumio[755]: info: Output device has changed, restarting Shairport Sync May 08 19:46:31 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:31 volumio-wk sudo[1033]: pam_unix(sudo:session): session closed for user root May 08 19:46:31 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:32 volumio-wk sudo[1036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 19:46:32 volumio-wk sudo[1036]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:32 volumio-wk sudo[1036]: pam_unix(sudo:session): session closed for user root May 08 19:46:32 volumio-wk sudo[1039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 19:46:32 volumio-wk sudo[1039]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:32 volumio-wk systemd[1]: Stopping Music Player Daemon... May 08 19:46:33 volumio-wk systemd[1]: mpd.service: Succeeded. May 08 19:46:33 volumio-wk systemd[1]: Stopped Music Player Daemon. May 08 19:46:33 volumio-wk systemd[1]: Starting Music Player Daemon... May 08 19:46:33 volumio-wk volumio[755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 19:46:33 volumio-wk volumio[755]: info: ___________ START PLUGINS ___________ May 08 19:46:33 volumio-wk volumio[755]: info: ControllerMpd::onStart: Initializing MPD May 08 19:46:33 volumio-wk volumio[755]: info: Creating MPD Configuration file May 08 19:46:34 volumio-wk sudo[1045]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 08 19:46:34 volumio-wk sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:34 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 19:46:34 volumio-wk volumio[755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 19:46:34 volumio-wk sudo[1045]: pam_unix(sudo:session): session closed for user root May 08 19:46:34 volumio-wk volumio[755]: info: [1746726394381] CoreMusicLibrary::Adding element Media Servers May 08 19:46:34 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 19:46:34 volumio-wk sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 19:46:35 volumio-wk sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:35 volumio-wk sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 19:46:35 volumio-wk sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:35 volumio-wk sudo[1047]: pam_unix(sudo:session): session closed for user root May 08 19:46:35 volumio-wk systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 08 19:46:35 volumio-wk systemd[1]: mpd.service: Succeeded. May 08 19:46:35 volumio-wk systemd[1]: Stopped Music Player Daemon. May 08 19:46:36 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:36 volumio-wk systemd[1]: Starting Music Player Daemon... May 08 19:46:36 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:37 volumio-wk sudo[1076]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 08 19:46:37 volumio-wk sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:37 volumio-wk sudo[1076]: pam_unix(sudo:session): session closed for user root May 08 19:46:37 volumio-wk volumio[755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 19:46:37 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:37 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:38 volumio-wk volumio[755]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 19:46:38 volumio-wk volumio[755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 19:46:38 volumio-wk volumio[755]: info: [1746726398312] CoreMusicLibrary::Adding element Last_100 May 08 19:46:38 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 19:46:38 volumio-wk volumio[755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 19:46:38 volumio-wk volumio[755]: info: [1746726398412] CoreMusicLibrary::Adding element Webradio May 08 19:46:38 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 19:46:38 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 19:46:38 volumio-wk volumio[755]: info: Initializing BBC Radios May 08 19:46:39 volumio-wk volumio[755]: Starting albumart workers May 08 19:46:39 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 19:46:39 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:40 volumio-wk volumio[755]: info: Creating Spotify config file May 08 19:46:40 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:42 volumio-wk volumio[755]: info: Volumio Calling Home May 08 19:46:46 volumio-wk volumio[755]: info: Discovery: adding 06a3179c-859c-4a99-b405-398a18f3ea14 May 08 19:46:46 volumio-wk volumio[755]: info: Discovery: Found device Volumio-wk May 08 19:46:46 volumio-wk volumio[755]: info: CoreCommandRouter::volumioGetState May 08 19:46:46 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:47 volumio-wk volumio[755]: info: MPD Permissions set May 08 19:46:47 volumio-wk volumio[755]: info: MPD Permissions set May 08 19:46:47 volumio-wk volumio[755]: info: Upmpdcli Daemon Started May 08 19:46:47 volumio-wk volumio[755]: info: VolumeController:: Volume=84 Mute =false May 08 19:46:47 volumio-wk volumio[755]: info: CoreStateMachine::pushState May 08 19:46:47 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:47 volumio-wk volumio[755]: info: CoreCommandRouter::volumioPushState May 08 19:46:47 volumio-wk volumio[755]: info: Volumio called home May 08 19:46:48 volumio-wk volumio[755]: info: Spotify config file written May 08 19:46:48 volumio-wk volumio[755]: info: CoreCommandRouter::volumioGetState May 08 19:46:48 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:46:48 volumio-wk sudo[1131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 08 19:46:48 volumio-wk sudo[1131]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:49 volumio-wk systemd[1]: Started go-librespot Daemon. May 08 19:46:49 volumio-wk go-librespot[1133]: Librespot-go daemon starting... May 08 19:46:49 volumio-wk sudo[1131]: pam_unix(sudo:session): session closed for user root May 08 19:46:50 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:50+02:00" level=info msg="generated new device id: 979a7b6ebbd2fd4f5d57e0b4ab77a8c235628d27" May 08 19:46:50 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:50+02:00" level=debug msg="stored credentials found for 8qfabslguer3f5szkbjv982c2" May 08 19:46:51 volumio-wk mpd_monitor.sh[387]: MPD Monitor Service: MPD Appears to be inactive, restarting May 08 19:46:51 volumio-wk systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 08 19:46:51 volumio-wk systemd[1]: mpd.service: Failed with result 'protocol'. May 08 19:46:51 volumio-wk systemd[1]: Failed to start Music Player Daemon. May 08 19:46:51 volumio-wk sudo[1049]: pam_unix(sudo:session): session closed for user root May 08 19:46:51 volumio-wk sudo[1039]: pam_unix(sudo:session): session closed for user root May 08 19:46:51 volumio-wk systemd[1]: Starting Music Player Daemon... May 08 19:46:52 volumio-wk volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 08 19:46:52 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:52 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:52 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:52 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:52 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk sudo[1149]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 08 19:46:53 volumio-wk sudo[1149]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:53 volumio-wk sudo[1149]: pam_unix(sudo:session): session closed for user root May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:53 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:54 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:46:54 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 19:46:54 volumio-wk volumio[755]: info: No need to fix Spotify hosts May 08 19:46:55 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:55+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]" May 08 19:46:55 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:55+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]" May 08 19:46:55 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:55+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]" May 08 19:46:55 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:55+02:00" level=debug msg="zeroconf server listening on port 35071" May 08 19:46:55 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:55+02:00" level=debug msg="obtained new client token: AABjcuyi9F6tg2sCFbLoOtrFoOXgbZHa8+SkgMGiNi0iEoN9FRjq7uoF25Xyc9O6XLKjN9LNnWYZv1d/lx2PSbHlk4kuWo/akjRUjzqTGTtmaGK0EkNXeiMd/xiwdMhrF4WAyiT6UBLOd9QbKmjciU/kKLz+IqLYoJkyfSdorNsUSs7Dre273JkI38tsHVImLdq9B2QJ2gEpKniAWTbeIsK9QgWf1cbmqTFxmH36O5Tuzw0IVSYZVvX4v0i+oA==" May 08 19:46:56 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:56+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" May 08 19:46:56 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:56+02:00" level=debug msg="completed keyexchange" May 08 19:46:56 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:56+02:00" level=debug msg="completed challenge" May 08 19:46:56 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:56+02:00" level=debug msg="authenticated as 8qfabslguer3f5szkbjv982c2" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="authenticated as 8qfabslguer3f5szkbjv982c2" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="dealer connection opened" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="initializing zeroconf session, username: 8qfabslguer3f5szkbjv982c2" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 08 19:46:57 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:57+02:00" level=debug msg="received connection id: MTkxNWRkYTMtYzY3MS00YTFkLWJkMTctMGNkOTlhZmNiZWM2K2RlYWxlcit0Y3A6Ly8wYWNhNThjMy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQ0ExOTA1MEZFRDdEREI3MTI3NDdFQzAzNzFDNjkwNUUzQkI5ODgyN0QyMDcxNkJCMEVDQjVFQzA2M0NDNUE1RQ==" May 08 19:46:57 volumio-wk volumio[755]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service May 08 19:46:57 volumio-wk volumio[755]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. May 08 19:46:57 volumio-wk volumio[755]: See "systemctl status mpd.service" and "journalctl -xe" for details. May 08 19:46:57 volumio-wk volumio[755]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service May 08 19:46:57 volumio-wk volumio[755]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. May 08 19:46:57 volumio-wk volumio[755]: See "systemctl status mpd.service" and "journalctl -xe" for details. May 08 19:46:58 volumio-wk volumio[755]: info: Completed starting Core Plugins May 08 19:46:58 volumio-wk volumio[755]: info: ------------------------------------------- May 08 19:46:58 volumio-wk volumio[755]: info: ----- MyVolumio plugins startup ---- May 08 19:46:58 volumio-wk volumio[755]: info: ------------------------------------------- May 08 19:46:58 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Fetching plans data.... May 08 19:46:58 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:58+02:00" level=debug msg="put connect state because NEW_DEVICE" May 08 19:46:58 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:58+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 08 19:46:58 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:58+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 08 19:46:58 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 08 19:46:58 volumio-wk go-librespot[1133]: time="2025-05-08T19:46:58+02:00" level=debug msg="autoplay enabled: false" May 08 19:46:58 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:46:58] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 08 19:46:58 volumio-wk volumio[755]: info: Listing playlists May 08 19:46:58 volumio-wk volumio[755]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 08 19:46:58 volumio-wk volumio[755]: SPOTIFY: BQBu5VtYNI5tTVzWkwHppFiqyIhFc1XDSwvIEN3i1bpdBdwDY6Spwdeypo8Ub53E9uIWimGYAwRkcb0U5IyfBsiaWABr7T8macQyjwQfVZYAzejM4i_YP2gVDJFxqd8PpCoRMNz_3O3PiYOFDq50eezBxo9U3jigUxePtnRa__8E0bXEnMvEASjcBezt-kdpzN2NSS7AggZpK39qDJj4LzQimmljtqas_ci0eS2W5w9xZ7v5KI-mjZSyhEs1ue_Hia13ZFlR0cLwj7jMajXQ9FdgqZppbEipdVNUpUj1euKQsSk May 08 19:46:58 volumio-wk volumio[755]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 08 19:46:58 volumio-wk volumio[755]: info: New Spotify access token = BQBu5VtYNI5tTVzWkwHppFiqyIhFc1XDSwvIEN3i1bpdBdwDY6Spwdeypo8Ub53E9uIWimGYAwRkcb0U5IyfBsiaWABr7T8macQyjwQfVZYAzejM4i_YP2gVDJFxqd8PpCoRMNz_3O3PiYOFDq50eezBxo9U3jigUxePtnRa__8E0bXEnMvEASjcBezt-kdpzN2NSS7AggZpK39qDJj4LzQimmljtqas_ci0eS2W5w9xZ7v5KI-mjZSyhEs1ue_Hia13ZFlR0cLwj7jMajXQ9FdgqZppbEipdVNUpUj1euKQsSk May 08 19:46:58 volumio-wk volumio[755]: info: Spotify credentials grant success - running version from March 24, 2019 May 08 19:46:58 volumio-wk volumio[755]: info: Starting Shairport Sync May 08 19:46:59 volumio-wk volumio[755]: info: Starting Shairport Sync May 08 19:46:59 volumio-wk volumio[755]: info: Starting Shairport Sync May 08 19:46:59 volumio-wk sudo[1176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 08 19:46:59 volumio-wk sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:46:59 volumio-wk sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 08 19:46:59 volumio-wk sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:47:00 volumio-wk sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 08 19:47:00 volumio-wk sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:47:00 volumio-wk systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 08 19:47:00 volumio-wk systemd[1]: shairport-sync.service: Succeeded. May 08 19:47:00 volumio-wk systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 08 19:47:00 volumio-wk volumio[755]: info: CoreCommandRouter::volumioGetState May 08 19:47:00 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:47:00 volumio-wk systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 08 19:47:00 volumio-wk volumio[755]: info: CoreCommandRouter::volumioGetState May 08 19:47:00 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:47:00 volumio-wk sudo[1176]: pam_unix(sudo:session): session closed for user root May 08 19:47:01 volumio-wk systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 08 19:47:01 volumio-wk systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 08 19:47:01 volumio-wk systemd[1]: shairport-sync.service: Succeeded. May 08 19:47:01 volumio-wk systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 08 19:47:01 volumio-wk systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 08 19:47:01 volumio-wk sudo[1180]: pam_unix(sudo:session): session closed for user root May 08 19:47:01 volumio-wk sudo[1178]: pam_unix(sudo:session): session closed for user root May 08 19:47:01 volumio-wk volumio[755]: info: go-librespot daemon successfully initialized May 08 19:47:01 volumio-wk volumio[755]: info: Shairport-Sync Started May 08 19:47:01 volumio-wk volumio[755]: Error adding Membership: Error: addMembership EINVAL May 08 19:47:01 volumio-wk volumio[755]: info: Shairport-Sync Started May 08 19:47:02 volumio-wk volumio[755]: SPOTIFY: User informations: {"country":"NL","display_name":"Groosman","email":"mclgroosman@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/8qfabslguer3f5szkbjv982c2"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/8qfabslguer3f5szkbjv982c2","id":"8qfabslguer3f5szkbjv982c2","images":[],"product":"premium","type":"user","uri":"spotify:user:8qfabslguer3f5szkbjv982c2"} May 08 19:47:02 volumio-wk volumio[755]: info: Spotify Successfully logged in May 08 19:47:02 volumio-wk volumio[755]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 19:47:02 volumio-wk volumio[755]: info: [1746726422342] CoreMusicLibrary::Adding element Spotify May 08 19:47:02 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 19:47:02 volumio-wk volumio[755]: Cannot find translation for source Spotify May 08 19:47:03 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:47:03] [connect] Successful connection May 08 19:47:03 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:47:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746726423 101 May 08 19:47:03 volumio-wk volumio[755]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 May 08 19:47:04 volumio-wk volumio[755]: info: Initializing connection to go-librespot Websocket May 08 19:47:04 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:04+02:00" level=debug msg="new websocket client" May 08 19:47:04 volumio-wk volumio[755]: info: Connection to go-librespot Websocket established May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 08 19:47:06 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin bluetooth to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin multiroom to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin metavolumio to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin cd_controller to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin smart_inputs to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: Adding plugin tidalconnect to MyMusic Plugins May 08 19:47:07 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 08 19:47:14 volumio-wk mpd[1161]: May 08 19:47 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 19:47:14 volumio-wk systemd[1]: Started Music Player Daemon. May 08 19:47:14 volumio-wk mpd_monitor.sh[387]: MPD Monitor Service: MPD restarted due to no mpc output. May 08 19:47:18 volumio-wk volumio[755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 08 19:47:18 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 08 19:47:18 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:47:19 volumio-wk volumio[755]: info: Starting MyVolumio Remote Streaming Endpoints May 08 19:47:19 volumio-wk volumio[755]: info: MyVolumio login type: Token May 08 19:47:19 volumio-wk volumio[755]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 08 19:47:19 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.2.12:36668->34.158.1.133:4070: use of closed network connection" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=debug msg="obtained new client token: AACPTUEXBiMGn2lWnF0WPlJzk6IEHlZp9C7Cx6SuJAvQwXFhtzFK96wQUZiecSnCQH/qStjWhbrcVo4zDNM28eqOK+thR6TOzj4onLvxu6zZ3H8oW5Oy4ihApA1ayzfbyIkv0IVyz33hnyphkgFStbx7snQ/aHnd17m8UeoE+83XJhkI/nekfVBSTfGKWnzVJzPNcVbg3M71/NABhE/425rs/duZDM4ZvBczeJsX5PK94iuzZerGs+wObRs=" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=debug msg="completed keyexchange" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=debug msg="completed challenge" May 08 19:47:22 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:22+02:00" level=debug msg="authenticated as 0asph8ch1n25ex1jsrbqdr0jr" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="authenticated as 0asph8ch1n25ex1jsrbqdr0jr" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="dealer connection opened" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=info msg="accepted zeroconf user 0asph8ch1n25ex1jsrbqdr0jr from iPhone" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="received connection id: OGI1MDE5MjUtODc4MC00M2FiLTlmY2YtMjhmZmIwZDZmMDIwK2RlYWxlcit0Y3A6Ly8wYWNhNThkYS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNTNGNUQ0MjczODFBMDJGNzZBMDA4MDlDNDY2MEE0NkQxQzQ2RUI0MzgxMzM1QkM4NDk0NkE5RTk2QUQyMEJGRA==" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="put connect state because NEW_DEVICE" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="autoplay enabled: false" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="handling transfer player command from bbfe73bdc7ea1db16bd57fea9ba2487175106de9" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:5wRN69WYl5HkLN0qpUDLCr" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=trace msg="fetched new page 0 with 106 items (list: 106)" uri="spotify:playlist:5wRN69WYl5HkLN0qpUDLCr" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="loading track (paused: true, position: 73222ms)" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=trace msg="emitting websocket event: will_play" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1711" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="selected format OGG_VORBIS_320 (11047e86b36f09c3975ec45d4daaf1dde0eb0048)" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:23 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:23+02:00" level=debug msg="requested aes key for file 11047e86b36f09c3975ec45d4daaf1dde0eb0048, gid: 6Dc2tCivms1s2X9myWe4ni" May 08 19:47:24 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:24+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1301" May 08 19:47:25 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:25+02:00" level=debug msg="fetched first chunk of 7, total size is 3584656 bytes" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:26 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:26+02:00" level=debug msg="fetched chunk 1/6, size: 524288" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="fetched chunk 6/6, size: 438928" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="fetched chunk 5/6, size: 524288" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="fetched chunk 3/6, size: 524288" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=trace msg="seek to 73222ms (diff: 61ms, samples: 3229090, bytes: 2950069)" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="fetched chunk 2/6, size: 524288" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=debug msg="created new output device" May 08 19:47:28 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:28+02:00" level=info msg="loaded track \"Tuyo (Narcos Theme) - A Netflix Original Series Soundtrack\" (paused: true, position: 73222ms, duration: 89293ms, prefetched: false)" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=trace msg="emitting websocket event: metadata" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=trace msg="emitting websocket event: active" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="sending successful reply for dealer request" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=trace msg="emitting websocket event: paused" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="handling resume player command from bbfe73bdc7ea1db16bd57fea9ba2487175106de9" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=trace msg="seek to 73222ms (diff: 61ms, samples: 3229090, bytes: 2950069)" uri="spotify:track:6Dc2tCivms1s2X9myWe4ni" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="resume track at 73161ms" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="sending successful reply for dealer request" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="prefetching next track" uri="spotify:track:2AX5E86cn9n2dgioZEjirI" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="selected format OGG_VORBIS_320 (85efa3be109caa06eea1a8169d9a127b11866e19)" uri="spotify:track:2AX5E86cn9n2dgioZEjirI" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="requested aes key for file 85efa3be109caa06eea1a8169d9a127b11866e19, gid: 2AX5E86cn9n2dgioZEjirI" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 08 19:47:29 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:29+02:00" level=trace msg="emitting websocket event: playing" May 08 19:47:30 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 336" May 08 19:47:30 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1767" May 08 19:47:30 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:30+02:00" level=debug msg="fetched first chunk of 17, total size is 8778324 bytes" uri="spotify:track:2AX5E86cn9n2dgioZEjirI" May 08 19:47:31 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:31+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2AX5E86cn9n2dgioZEjirI" May 08 19:47:31 volumio-wk go-librespot[1133]: time="2025-05-08T19:47:31+02:00" level=trace msg="closed output device because of stop command" May 08 19:47:31 volumio-wk go-librespot[1133]: panic: runtime error: invalid memory address or nil pointer dereference May 08 19:47:31 volumio-wk go-librespot[1133]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x57277c] May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 160 gp=0x1f4d0e8 m=7 mp=0x2034008 [running]: May 08 19:47:31 volumio-wk go-librespot[1133]: panic({0x5eab20, 0xa60098}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:779 +0x12c fp=0x1de2de8 sp=0x1de2d94 pc=0x58364 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.panicmem(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:261 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.sigpanic() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/signal_unix.go:881 +0x39c fp=0x1de2e18 sp=0x1de2de8 pc=0x74350 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*AppPlayer).prefetchNext(0x1dbb130) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:42 +0x4c4 fp=0x1de2fe4 sp=0x1de2e1c pc=0x57277c May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*AppPlayer).schedulePrefetchNext.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:56 +0x28 fp=0x1de2fec sp=0x1de2fe4 pc=0x572d68 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1de2fec sp=0x1de2fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by main.(*AppPlayer).schedulePrefetchNext in goroutine 101 May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:56 +0x1c8 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 1 gp=0x1c02128 m=nil [select]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d83d0c sp=0x1d83cf8 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.selectgo(0x1d83e0c, 0x1d15dd8, 0x0, 0x0, 0x2, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1d83dac sp=0x1d83d0c pc=0x705e4 May 08 19:47:31 volumio-wk go-librespot[1133]: go-librespot/zeroconf.(*Zeroconf).Serve(0x1fe9810, 0x1d83e88) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:268 +0x228 fp=0x1d83e50 sp=0x1d83dac pc=0x528c80 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*App).withAppPlayer(0x1c003f0, 0x1d3e0c0) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:297 +0x4b0 fp=0x1d83ec0 sp=0x1d83e50 pc=0x578aac May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*App).withCredentials(0x1c003f0, {0x5f3170, 0x1c0e520}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:171 +0x3d4 fp=0x1d83f1c sp=0x1d83ec0 pc=0x578184 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*App).SpotifyToken(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:131 May 08 19:47:31 volumio-wk go-librespot[1133]: main.main() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:466 +0x530 fp=0x1d83fa8 sp=0x1d83f1c pc=0x57a0cc May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.main() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:271 +0x2fc fp=0x1d83fec sp=0x1d83fa8 pc=0x5c29c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d83fec sp=0x1d83fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 2 gp=0x1c02a28 m=nil [force gc (idle)]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0xaa84c0, 0x11, 0xa, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c42fd4 sp=0x1c42fc0 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.forcegchelper() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:326 +0xe4 fp=0x1c42fec sp=0x1c42fd4 pc=0x5c668 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c42fec sp=0x1c42fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by runtime.init.5 in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:314 +0x1c May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 3 gp=0x1c02b48 m=nil [runnable]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goschedIfBusy() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:365 +0x34 fp=0x1c437c4 sp=0x1c437b8 pc=0x5c714 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.bgsweep(0x1c6a000) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcsweep.go:302 +0x188 fp=0x1c437e4 sp=0x1c437c4 pc=0x450d8 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gcenable.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x28 fp=0x1c437ec sp=0x1c437e4 pc=0x3518c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c437ec sp=0x1c437ec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by runtime.gcenable in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x74 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 4 gp=0x1c02c68 m=nil [GC scavenge wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0xaa9020, 0xd, 0xa, 0x2) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c43fb4 sp=0x1c43fa0 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.(*scavengerState).park(0xaa9020) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:425 +0x68 fp=0x1c43fc8 sp=0x1c43fb4 pc=0x4238c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.bgscavenge(0x1c6a000) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:658 +0x60 fp=0x1c43fe4 sp=0x1c43fc8 pc=0x42ac4 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gcenable.gowrap2() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0x28 fp=0x1c43fec sp=0x1c43fe4 pc=0x35138 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c43fec sp=0x1c43fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by runtime.gcenable in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0xbc May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 5 gp=0x1c02fc8 m=nil [finalizer wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f7e4, 0xad3bac, 0x10, 0xa, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c4478c sp=0x1c44778 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.runfinq() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:194 +0x110 fp=0x1c447ec sp=0x1c4478c pc=0x33f78 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c447ec sp=0x1c447ec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by runtime.createfing in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:164 +0x5c May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 6 gp=0x1c037a8 m=nil [IO wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3f08, 0x2, 0x2, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c425dc sp=0x1c425c8 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3ef8, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c425f4 sp=0x1c425dc pc=0x540f0 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3ef8, 0x72) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c42608 sp=0x1c425f4 pc=0x8eba8 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1c26fb8, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c4261c sp=0x1c42608 pc=0x108108 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*FD).Accept(0x1c26fa0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x1c42664 sp=0x1c4261c pc=0x10c974 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*netFD).accept(0x1c26fa0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x1c426cc sp=0x1c42664 pc=0x2a2504 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*TCPListener).accept(0x1c883a8) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x1c426e4 sp=0x1c426cc pc=0x2ba604 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*TCPListener).Accept(0x1c883a8) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x1c42700 sp=0x1c426e4 pc=0x2b9670 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*onceCloseListener).Accept(0x1d3e4e0) May 08 19:47:31 volumio-wk go-librespot[1133]: :1 +0x34 fp=0x1c42718 sp=0x1c42700 pc=0x45e914 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Server).Serve(0x1c7f688, {0x72527c, 0x1c883a8}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x1c427b0 sp=0x1c42718 pc=0x43cfd0 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.Serve(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*ApiServer).serve(0x1c6fa00) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:470 +0x5ec fp=0x1c427e4 sp=0x1c427b0 pc=0x57084c May 08 19:47:31 volumio-wk go-librespot[1133]: main.NewApiServer.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x28 fp=0x1c427ec sp=0x1c427e4 pc=0x56ff20 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c427ec sp=0x1c427ec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by main.NewApiServer in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x224 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 16 gp=0x1c038c8 m=nil [GC worker (idle)]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f7f4, 0x1fcaa80, 0x1a, 0xa, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c44f90 sp=0x1c44f7c pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gcBgMarkWorker() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x1c44fec sp=0x1c44f90 pc=0x37db4 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c44fec sp=0x1c44fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by runtime.gcBgMarkStartWorkers in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 99 gp=0x1c039e8 m=nil [select]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d81e7c sp=0x1d81e68 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.selectgo(0x1d81fcc, 0x1d81f44, 0x0, 0x0, 0x3, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1d81f1c sp=0x1d81e7c pc=0x705e4 May 08 19:47:31 volumio-wk go-librespot[1133]: go-librespot/player.(*Player).manageLoop(0x1e19040) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/player/player.go:109 +0x1e0 fp=0x1d81fe4 sp=0x1d81f1c pc=0x4a730c May 08 19:47:31 volumio-wk go-librespot[1133]: go-librespot/player.NewPlayer.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x28 fp=0x1d81fec sp=0x1d81fe4 pc=0x4a7040 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d81fec sp=0x1d81fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by go-librespot/player.NewPlayer in goroutine 1 May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x1e4 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 14 gp=0x1c03b08 m=nil [IO wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3e68, 0x2, 0x2, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c58ad4 sp=0x1c58ac0 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3e58, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c58aec sp=0x1c58ad4 pc=0x540f0 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3e58, 0x72) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c58b00 sp=0x1c58aec pc=0x8eba8 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1c27288, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c58b14 sp=0x1c58b00 pc=0x108108 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1c27270, {0x1d68000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1c58b5c sp=0x1c58b14 pc=0x1092f4 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1c27270, {0x1d68000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1c58b88 sp=0x1c58b5c pc=0x2a0610 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1c2e958, {0x1d68000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1c58bb4 sp=0x1c58b88 pc=0x2b07f0 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1c2e958, {0x1d68000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1c58bd4 sp=0x1c58bb4 pc=0x2c3a44 May 08 19:47:31 volumio-wk go-librespot[1133]: crypto/tls.(*atLeastReader).Read(0x1fed370, {0x1d68000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x1c58c00 sp=0x1c58bd4 pc=0x386018 May 08 19:47:31 volumio-wk go-librespot[1133]: bytes.(*Buffer).ReadFrom(0x1cc660c, {0x723a98, 0x1fed370}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x1c58c3c sp=0x1c58c00 pc=0x136d6c May 08 19:47:31 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readFromUntil(0x1cc6488, {0x722604, 0x1c2e958}, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x1c58c64 sp=0x1c58c3c pc=0x386274 May 08 19:47:31 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1cc6488, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x1c58dc8 sp=0x1c58c64 pc=0x383974 May 08 19:47:31 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:31 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1cc6488, {0x2010000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1c58df8 sp=0x1c58dc8 pc=0x3897e4 May 08 19:47:31 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x1ff5560, {0x1c8cc24, 0x9, 0x9}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x1c58e1c sp=0x1c58df8 pc=0x15ab44 May 08 19:47:31 volumio-wk go-librespot[1133]: io.ReadAtLeast({0x7227f8, 0x1ff5560}, {0x1c8cc24, 0x9, 0x9}, 0x9) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x1c58e48 sp=0x1c58e1c pc=0x1020b0 May 08 19:47:31 volumio-wk go-librespot[1133]: io.ReadFull(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.http2readFrameHeader({0x1c8cc24, 0x9, 0x9}, {0x7227f8, 0x1ff5560}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x1c58e70 sp=0x1c58e48 pc=0x3f30fc May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2Framer).ReadFrame(0x1c8cc00) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x1c58eec sp=0x1c58e70 pc=0x3f3894 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2clientConnReadLoop).run(0x1c58fdc) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x1c58fa4 sp=0x1c58eec pc=0x4180b0 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).readLoop(0x1cad208) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x1c58fe4 sp=0x1c58fa4 pc=0x4175a4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2Transport).newClientConn.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x1c58fec sp=0x1c58fe4 pc=0x4105f0 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c58fec sp=0x1c58fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by net/http.(*http2Transport).newClientConn in goroutine 13 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 72 gp=0x1e4a488 m=nil [IO wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c38c8, 0x2, 0x2, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d868a4 sp=0x1d86890 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c38b8, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1d868bc sp=0x1d868a4 pc=0x540f0 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c38b8, 0x72) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1d868d0 sp=0x1d868bc pc=0x8eba8 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1dbaba8, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1d868e4 sp=0x1d868d0 pc=0x108108 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1dbab90, {0x1ded000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1d8692c sp=0x1d868e4 pc=0x1092f4 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1dbab90, {0x1ded000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1d86958 sp=0x1d8692c pc=0x2a0610 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1dbc3c0, {0x1ded000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1d86984 sp=0x1d86958 pc=0x2b07f0 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1dbc3c0, {0x1ded000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1d869a4 sp=0x1d86984 pc=0x2c3a44 May 08 19:47:31 volumio-wk go-librespot[1133]: io.(*multiReader).Read(0x1e012f0, {0x1ded000, 0x1000, 0x1000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/multi.go:26 +0xb4 fp=0x1d869d0 sp=0x1d869a4 pc=0x103318 May 08 19:47:31 volumio-wk go-librespot[1133]: bufio.(*Reader).fill(0x1dd0ea0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x1d869f4 sp=0x1d869d0 pc=0x15a4b8 May 08 19:47:31 volumio-wk go-librespot[1133]: bufio.(*Reader).ReadByte(0x1dd0ea0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x28 fp=0x1d86a00 sp=0x1d869f4 pc=0x15ad3c May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.readFrameHeader(0x1dd0ea0, {0x1cf76b8, 0x8, 0x8}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x1d86a40 sp=0x1d86a00 pc=0x4771e0 May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x1cf7688, {0x725688, 0xad3b20}) May 08 19:47:31 volumio-wk volumio[755]: info: Starting Streaming Service Transparent Proxy May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x1d86b00 sp=0x1d86a40 pc=0x479e44 May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).readLoop(0x1cf7688, {0x725688, 0xad3b20}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x1d86bc4 sp=0x1d86b00 pc=0x47992c May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).reader(0x1cf7688, {0x725688, 0xad3b20}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x1d86c50 sp=0x1d86bc4 pc=0x47ab40 May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).Reader(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 May 08 19:47:31 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).Read(0x1cf7688, {0x725688, 0xad3b20}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x1d86c78 sp=0x1d86c50 pc=0x479210 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*ApiServer).serve.func14({0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:450 +0x22c fp=0x1d86cd0 sp=0x1d86c78 pc=0x570c88 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.HandlerFunc.ServeHTTP(0x1c2e880, {0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x1d86ce0 sp=0x1d86cd0 pc=0x4395b4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*ServeMux).ServeHTTP(0x1c8ca00, {0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2683 +0x208 fp=0x1d86d1c sp=0x1d86ce0 pc=0x43b414 May 08 19:47:31 volumio-wk go-librespot[1133]: main.(*ApiServer).serve.(*ApiServer).allowOriginMiddleware.func15({0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:273 +0xa4 fp=0x1d86d40 sp=0x1d86d1c pc=0x570a44 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.HandlerFunc.ServeHTTP(0x1c0e700, {0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x1d86d50 sp=0x1d86d40 pc=0x4395b4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.serverHandler.ServeHTTP({0x1c7f688}, {0x7253b0, 0x1dbe328}, 0x1dbe288) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3137 +0xe0 fp=0x1d86d6c sp=0x1d86d50 pc=0x43cba4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*conn).serve(0x1dacf00, {0x7256a8, 0x1c88588}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2039 +0x61c fp=0x1d86fdc sp=0x1d86d6c pc=0x437df4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Server).Serve.gowrap3() May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x38 fp=0x1d86fec sp=0x1d86fdc pc=0x43d448 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d86fec sp=0x1d86fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by net/http.(*Server).Serve in goroutine 6 May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x468 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 20 gp=0x1e4a5a8 m=nil [runnable]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3d28, 0x2, 0x2, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c54e84 sp=0x1c54e70 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3d18, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c54e9c sp=0x1c54e84 pc=0x540f0 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3d18, 0x72) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c54eb0 sp=0x1c54e9c pc=0x8eba8 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1fe8068, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c54ec4 sp=0x1c54eb0 pc=0x108108 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*FD).RawRead(0x1fe8050, 0x1ff5e00) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x1c54ef0 sp=0x1c54ec4 pc=0x10d578 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*rawConn).Read(0x1ff6080, 0x1ff5e00) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x1c54f10 sp=0x1c54ef0 pc=0x2b4a2c May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x1fec060, 0x1ff5dd0, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x1c54f40 sp=0x1c54f10 pc=0x4c9804 May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x1ff4038, {0x2048000, 0x10000, 0x10000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv4/payload_cmsg.go:32 +0x44c fp=0x1c54f9c sp=0x1c54f40 pc=0x4cd7ec May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/grandcat/zeroconf.(*Server).recv4(0x1fc4240, 0x1ff4030) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xec fp=0x1c54fe0 sp=0x1c54f9c pc=0x52407c May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x1c54fec sp=0x1c54fe0 pc=0x523d34 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c54fec sp=0x1c54fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 18 May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 21 gp=0x1e4a6c8 m=nil [IO wait]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3c88, 0x2, 0x2, 0x5) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c40e5c sp=0x1c40e48 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3c78, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c40e74 sp=0x1c40e5c pc=0x540f0 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3c78, 0x72) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c40e88 sp=0x1c40e74 pc=0x8eba8 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1fe80b8, 0x72, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c40e9c sp=0x1c40e88 pc=0x108108 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:31 volumio-wk go-librespot[1133]: internal/poll.(*FD).RawRead(0x1fe80a0, 0x1ff41b0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x1c40ec8 sp=0x1c40e9c pc=0x10d578 May 08 19:47:31 volumio-wk go-librespot[1133]: net.(*rawConn).Read(0x1ff60a0, 0x1ff41b0) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x1c40ee8 sp=0x1c40ec8 pc=0x2b4a2c May 08 19:47:31 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 08 19:47:31 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x1fec070, 0x1ff4180, 0x0) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x1c40f18 sp=0x1c40ee8 pc=0x4c9804 May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 May 08 19:47:31 volumio-wk go-librespot[1133]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x1ff4068, {0x2038000, 0x10000, 0x10000}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv6/payload_cmsg.go:32 +0x2ec fp=0x1c40f9c sp=0x1c40f18 pc=0x4d1174 May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/grandcat/zeroconf.(*Server).recv6(0x1fc4240, 0x1ff4060) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xec fp=0x1c40fe0 sp=0x1c40f9c pc=0x524270 May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x1c40fec sp=0x1c40fe0 pc=0x523cd8 May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c40fec sp=0x1c40fec pc=0x9346c May 08 19:47:31 volumio-wk go-librespot[1133]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 18 May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 May 08 19:47:31 volumio-wk go-librespot[1133]: goroutine 101 gp=0x1e4ad88 m=nil [select]: May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d12e9c sp=0x1d12e88 pc=0x5c82c May 08 19:47:31 volumio-wk go-librespot[1133]: runtime.selectgo(0x1d12fa8, 0x1d12f60, 0x0, 0x0, 0x4, 0x1) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1d12f3c sp=0x1d12e9c pc=0x705e4 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).RoundTrip(0x1cad608, 0x1ed9048) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8354 +0x430 fp=0x1d12fec sp=0x1d12f3c pc=0x412adc May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2Transport).RoundTripOpt(0x1ca5020, 0x1ed9048, {0x0}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7622 +0x208 fp=0x1d13088 sp=0x1d12fec pc=0x40e8a0 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*http2Transport).RoundTrip(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7571 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.http2noDialH2RoundTripper.RoundTrip({0x1ca5020}, 0x1ed9048) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:10198 +0x30 fp=0x1d130b0 sp=0x1d13088 pc=0x41d058 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Transport).roundTrip(0xa67ab0, 0x1ed9048) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:553 +0x3c4 fp=0x1d131cc sp=0x1d130b0 pc=0x44905c May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Transport).RoundTrip(0xa67ab0, 0x1ed9048) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/roundtrip.go:17 +0x24 fp=0x1d131e4 sp=0x1d131cc pc=0x42d82c May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.send(0x1ed9048, {0x72294c, 0xa67ab0}, {0x0, 0x0, 0x0}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:259 +0x540 fp=0x1d13310 sp=0x1d131e4 pc=0x3e8554 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Client).send(0x1e11420, 0x1ed9048, {0x0, 0x0, 0x0}) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:180 +0x98 fp=0x1d13354 sp=0x1d13310 pc=0x3e7e48 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Client).do(0x1e11420, 0x1ed9048) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:724 +0x8bc fp=0x1d13464 sp=0x1d13354 pc=0x3ea248 May 08 19:47:31 volumio-wk go-librespot[1133]: net/http.(*Client).Do(...) May 08 19:47:31 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:590 May 08 19:47:31 volumio-wk go-librespot[1133]: go-librespot/spclient.(*Spclient).request.func2() May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:83 +0x214 fp=0x1d134b0 sp=0x1d13464 pc=0x4a2664 May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x1d135b4, {0x724b70, 0x1ff3020}, 0x0, {0x0, 0x0}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:88 +0xf0 fp=0x1d13530 sp=0x1d134b0 pc=0x496294 May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.RetryNotifyWithData[...](...) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:54 May 08 19:47:31 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.RetryWithData[...](0x1d135b4, {0x724b70, 0x1ff3020}) May 08 19:47:31 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:43 +0x54 fp=0x1d1355c sp=0x1d13530 pc=0x49617c May 08 19:47:31 volumio-wk go-librespot[1133]: go-librespot/spclient.(*Spclient).request(0x1e11400, {0x665295, 0x3}, {0x1ee0000, 0x4b}, 0x1d137d4, 0x1d1370c, {0x0, 0x0, 0x0}) May 08 19:47:32 volumio-wk volumio[755]: info: Streaming services startup May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:75 +0x378 fp=0x1d135fc sp=0x1d1355c pc=0x4a22d4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/spclient.(*Spclient).PutConnectStateInactive(0x1e11400, {0x1e34410, 0xc8}, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:106 +0x2b4 fp=0x1d137fc sp=0x1d135fc pc=0x4a2b68 May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*AppPlayer).putConnectState(0x1dbb130, 0x7) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/state.go:114 +0x428 fp=0x1d13890 sp=0x1d137fc pc=0x57ef1c May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*AppPlayer).handleDealerMessage(0x1dbb130, {{0x202d5e0, 0x1d}, 0x1dae8c0, {0x24c2000, 0xa7f7, 0xe000}}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:114 +0x438 fp=0x1d138fc sp=0x1d13890 pc=0x57ab24 May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*AppPlayer).Run(0x1dbb130, 0x1e46ac0) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:438 +0x318 fp=0x1d13fe0 sp=0x1d138fc pc=0x57e06c May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*App).withAppPlayer.func3.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:321 +0x30 fp=0x1d13fec sp=0x1d13fe0 pc=0x578f08 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d13fec sp=0x1d13fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by main.(*App).withAppPlayer.func3 in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:321 +0x2f8 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 29 gp=0x1e4aea8 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3be8, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c57ad4 sp=0x1c57ac0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3bd8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c57aec sp=0x1c57ad4 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3bd8, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c57b00 sp=0x1c57aec pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1fe9dc8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c57b14 sp=0x1c57b00 pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk volumio[755]: info: Starting Streaming Daemon May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1fe9db0, {0x2031000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1c57b5c sp=0x1c57b14 pc=0x1092f4 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1fe9db0, {0x2031000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1c57b88 sp=0x1c57b5c pc=0x2a0610 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1ff67a8, {0x2031000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1c57bb4 sp=0x1c57b88 pc=0x2b07f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1ff67a8, {0x2031000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1c57bd4 sp=0x1c57bb4 pc=0x2c3a44 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*atLeastReader).Read(0x1e01c20, {0x2031000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x1c57c00 sp=0x1c57bd4 pc=0x386018 May 08 19:47:32 volumio-wk go-librespot[1133]: bytes.(*Buffer).ReadFrom(0x1cc714c, {0x723a98, 0x1e01c20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x1c57c3c sp=0x1c57c00 pc=0x136d6c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readFromUntil(0x1cc6fc8, {0x722604, 0x1ff67a8}, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x1c57c64 sp=0x1c57c3c pc=0x386274 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1cc6fc8, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x1c57dc8 sp=0x1c57c64 pc=0x383974 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1cc6fc8, {0x205b000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1c57df8 sp=0x1c57dc8 pc=0x3897e4 May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x1ff5e60, {0x1c8d2a4, 0x9, 0x9}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x1c57e1c sp=0x1c57df8 pc=0x15ab44 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadAtLeast({0x7227f8, 0x1ff5e60}, {0x1c8d2a4, 0x9, 0x9}, 0x9) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x1c57e48 sp=0x1c57e1c pc=0x1020b0 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadFull(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.http2readFrameHeader({0x1c8d2a4, 0x9, 0x9}, {0x7227f8, 0x1ff5e60}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x1c57e70 sp=0x1c57e48 pc=0x3f30fc May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Framer).ReadFrame(0x1c8d280) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x1c57eec sp=0x1c57e70 pc=0x3f3894 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2clientConnReadLoop).run(0x1c57fdc) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x1c57fa4 sp=0x1c57eec pc=0x4180b0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).readLoop(0x1cad408) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x1c57fe4 sp=0x1c57fa4 pc=0x4175a4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Transport).newClientConn.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x1c57fec sp=0x1c57fe4 pc=0x4105f0 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c57fec sp=0x1c57fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*http2Transport).newClientConn in goroutine 28 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 97 gp=0x1c125a8 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c416a8 sp=0x1c41694 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c417a4, 0x1c4176c, 0x0, 0x0, 0x5, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c41748 sp=0x1c416a8 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x1cf7908) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x1c417e4 sp=0x1c41748 pc=0x47408c May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.newConn.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x1c417ec sp=0x1c417e4 pc=0x473c80 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c417ec sp=0x1c417ec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by nhooyr.io/websocket.newConn in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 42 gp=0x1c126c8 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3aa8, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c59ad4 sp=0x1c59ac0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3a98, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c59aec sp=0x1c59ad4 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3a98, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c59b00 sp=0x1c59aec pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x207f418, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c59b14 sp=0x1c59b00 pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x207f400, {0x2063000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1c59b5c sp=0x1c59b14 pc=0x1092f4 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x207f400, {0x2063000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1c59b88 sp=0x1c59b5c pc=0x2a0610 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1c2ebc0, {0x2063000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1c59bb4 sp=0x1c59b88 pc=0x2b07f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1c2ebc0, {0x2063000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1c59bd4 sp=0x1c59bb4 pc=0x2c3a44 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*atLeastReader).Read(0x1e44480, {0x2063000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x1c59c00 sp=0x1c59bd4 pc=0x386018 May 08 19:47:32 volumio-wk go-librespot[1133]: bytes.(*Buffer).ReadFrom(0x1cc7ecc, {0x723a98, 0x1e44480}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x1c59c3c sp=0x1c59c00 pc=0x136d6c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readFromUntil(0x1cc7d48, {0x722604, 0x1c2ebc0}, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x1c59c64 sp=0x1c59c3c pc=0x386274 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1cc7d48, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x1c59dc8 sp=0x1c59c64 pc=0x383974 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1cc7d48, {0x1d31000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1c59df8 sp=0x1c59dc8 pc=0x3897e4 May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x1c169c0, {0x1c8d7a4, 0x9, 0x9}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x1c59e1c sp=0x1c59df8 pc=0x15ab44 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadAtLeast({0x7227f8, 0x1c169c0}, {0x1c8d7a4, 0x9, 0x9}, 0x9) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x1c59e48 sp=0x1c59e1c pc=0x1020b0 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadFull(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.http2readFrameHeader({0x1c8d7a4, 0x9, 0x9}, {0x7227f8, 0x1c169c0}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x1c59e70 sp=0x1c59e48 pc=0x3f30fc May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Framer).ReadFrame(0x1c8d780) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x1c59eec sp=0x1c59e70 pc=0x3f3894 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2clientConnReadLoop).run(0x1c59fdc) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x1c59fa4 sp=0x1c59eec pc=0x4180b0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).readLoop(0x1cad508) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x1c59fe4 sp=0x1c59fa4 pc=0x4175a4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Transport).newClientConn.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x1c59fec sp=0x1c59fe4 pc=0x4105f0 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c59fec sp=0x1c59fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*http2Transport).newClientConn in goroutine 41 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 98 gp=0x1c12908 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c3f688 sp=0x1c3f674 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c3f7d4, 0x1c3f750, 0x0, 0x0, 0x2, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c3f728 sp=0x1c3f688 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/dealer.(*Dealer).pingTicker(0x1dbf0e8) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:107 +0x8c fp=0x1c3f7e4 sp=0x1c3f728 pc=0x4b85d0 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/dealer.NewDealer.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x1c3f7ec sp=0x1c3f7e4 pc=0x4b80a0 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c3f7ec sp=0x1c3f7ec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/dealer.NewDealer in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x180 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 86 gp=0x1c12b48 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c45ea8 sp=0x1c45e94 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c45fd4, 0x1c45f6c, 0x0, 0x0, 0x2, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c45f48 sp=0x1c45ea8 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x1dbed28) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:319 +0x8c fp=0x1c45fe4 sp=0x1c45f48 pc=0x48d514 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/ap.NewAccesspoint.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x28 fp=0x1c45fec sp=0x1c45fe4 pc=0x48b71c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c45fec sp=0x1c45fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/ap.NewAccesspoint in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x188 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 58 gp=0x1c12d88 m=nil [chan receive]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f7c8, 0x1c6a270, 0xe, 0x7, 0x2) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d8f748 sp=0x1d8f734 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv(0x1c6a240, 0x1d8f7d0, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x1d8f784 sp=0x1d8f748 pc=0x1fdc4 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv2(0x1c6a240, 0x1d8f7d0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x1d8f798 sp=0x1d8f784 pc=0x1f908 May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*App).withAppPlayer.func1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:245 +0x54 fp=0x1d8f7ec sp=0x1d8f798 pc=0x57937c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d8f7ec sp=0x1d8f7ec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by main.(*App).withAppPlayer in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:242 +0x3d4 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 59 gp=0x1c12ea8 m=nil [chan receive]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f7c8, 0x1c6a1f0, 0xe, 0x7, 0x2) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d8ff3c sp=0x1d8ff28 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv(0x1c6a1c0, 0x1d8ffe0, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x1d8ff78 sp=0x1d8ff3c pc=0x1fdc4 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv2(0x1c6a1c0, 0x1d8ffe0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x1d8ff8c sp=0x1d8ff78 pc=0x1f908 May 08 19:47:32 volumio-wk go-librespot[1133]: main.(*App).withAppPlayer.func2() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:261 +0x5c fp=0x1d8ffec sp=0x1d8ff8c pc=0x578f90 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d8ffec sp=0x1d8ffec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by main.(*App).withAppPlayer in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:258 +0x45c May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 60 gp=0x1c12fc8 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3dc8, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d905e8 sp=0x1d905d4 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3db8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1d90600 sp=0x1d905e8 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3db8, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1d90614 sp=0x1d90600 pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1fe8018, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1d90628 sp=0x1d90614 pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Accept(0x1fe8000) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x1d90670 sp=0x1d90628 pc=0x10c974 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).accept(0x1fe8000) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x1d906d8 sp=0x1d90670 pc=0x2a2504 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPListener).accept(0x200e048) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x1d906f0 sp=0x1d906d8 pc=0x2ba604 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPListener).Accept(0x200e048) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x1d9070c sp=0x1d906f0 pc=0x2b9670 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*onceCloseListener).Accept(0x1c151c0) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x34 fp=0x1d90724 sp=0x1d9070c pc=0x45e914 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Server).Serve(0x1c7e828, {0x72527c, 0x200e048}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x1d907bc sp=0x1d90724 pc=0x43cfd0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.Serve(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/zeroconf.(*Zeroconf).Serve.func2() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x8c fp=0x1d907ec sp=0x1d907bc pc=0x528d7c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d907ec sp=0x1d907ec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x160 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 102 gp=0x1c130e8 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3b48, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c55d70 sp=0x1c55d5c pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3b38, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1c55d88 sp=0x1c55d70 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3b38, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1c55d9c sp=0x1c55d88 pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1dbb3c8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1c55db0 sp=0x1c55d9c pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1dbb3b0, {0x1ff8cbc, 0x3, 0x3}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1c55df8 sp=0x1c55db0 pc=0x1092f4 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1dbb3b0, {0x1ff8cbc, 0x3, 0x3}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1c55e24 sp=0x1c55df8 pc=0x2a0610 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1dbca28, {0x1ff8cbc, 0x3, 0x3}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1c55e50 sp=0x1c55e24 pc=0x2b07f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1dbca28, {0x1ff8cbc, 0x3, 0x3}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1c55e70 sp=0x1c55e50 pc=0x2c3a44 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadAtLeast({0x722604, 0x1dbca28}, {0x1ff8cbc, 0x3, 0x3}, 0x3) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x1c55e9c sp=0x1c55e70 pc=0x1020b0 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadFull(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/ap.(*shannonConn).receivePacket(0x1dd1da0) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/shannon.go:80 +0x130 fp=0x1c55efc sp=0x1c55e9c pc=0x48fedc May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/ap.(*Accesspoint).recvLoop(0x1dbed28) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:251 +0x58 fp=0x1c55fe4 sp=0x1c55efc pc=0x48cda4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x28 fp=0x1c55fec sp=0x1c55fe4 pc=0x48cd20 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c55fec sp=0x1c55fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 101 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x60 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 74 gp=0x1d9afc8 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c3fea8 sp=0x1c3fe94 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c3ffa4, 0x1c3ff6c, 0x0, 0x0, 0x5, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c3ff48 sp=0x1c3fea8 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x1cf7688) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x1c3ffe4 sp=0x1c3ff48 pc=0x47408c May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.newConn.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x1c3ffec sp=0x1c3ffe4 pc=0x473c80 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c3ffec sp=0x1c3ffec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by nhooyr.io/websocket.newConn in goroutine 72 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 108 gp=0x1d9b0e8 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c53c9c sp=0x1c53c88 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c53dfc, 0x1c53d68, 0x0, 0x0, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c53d3c sp=0x1c53c9c pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/audio.(*KeyProvider).recvLoop(0x1dc58f0) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:52 +0x118 fp=0x1c53fe4 sp=0x1c53d3c pc=0x49552c May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/audio.(*KeyProvider).Request.(*KeyProvider).startReceiving.func1.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x28 fp=0x1c53fec sp=0x1c53fe4 pc=0x4960c8 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c53fec sp=0x1c53fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*KeyProvider).Request.(*KeyProvider).startReceiving.func1 in goroutine 101 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x60 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 70 gp=0x1d9b208 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3968, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d87ad4 sp=0x1d87ac0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c3958, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1d87aec sp=0x1d87ad4 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c3958, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1d87b00 sp=0x1d87aec pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1dba8d8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1d87b14 sp=0x1d87b00 pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1dba8c0, {0x1dd2000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1d87b5c sp=0x1d87b14 pc=0x1092f4 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1dba8c0, {0x1dd2000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1d87b88 sp=0x1d87b5c pc=0x2a0610 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1dbc030, {0x1dd2000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1d87bb4 sp=0x1d87b88 pc=0x2b07f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1dbc030, {0x1dd2000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1d87bd4 sp=0x1d87bb4 pc=0x2c3a44 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*atLeastReader).Read(0x1fecef0, {0x1dd2000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x1d87c00 sp=0x1d87bd4 pc=0x386018 May 08 19:47:32 volumio-wk go-librespot[1133]: bytes.(*Buffer).ReadFrom(0x1d595cc, {0x723a98, 0x1fecef0}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x1d87c3c sp=0x1d87c00 pc=0x136d6c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readFromUntil(0x1d59448, {0x722604, 0x1dbc030}, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x1d87c64 sp=0x1d87c3c pc=0x386274 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1d59448, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x1d87dc8 sp=0x1d87c64 pc=0x383974 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1d59448, {0x1de6000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1d87df8 sp=0x1d87dc8 pc=0x3897e4 May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x1dd07e0, {0x1db2224, 0x9, 0x9}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x1d87e1c sp=0x1d87df8 pc=0x15ab44 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadAtLeast({0x7227f8, 0x1dd07e0}, {0x1db2224, 0x9, 0x9}, 0x9) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x1d87e48 sp=0x1d87e1c pc=0x1020b0 May 08 19:47:32 volumio-wk go-librespot[1133]: io.ReadFull(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.http2readFrameHeader({0x1db2224, 0x9, 0x9}, {0x7227f8, 0x1dd07e0}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x1d87e70 sp=0x1d87e48 pc=0x3f30fc May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Framer).ReadFrame(0x1db2200) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x1d87eec sp=0x1d87e70 pc=0x3f3894 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2clientConnReadLoop).run(0x1d87fdc) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x1d87fa4 sp=0x1d87eec pc=0x4180b0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).readLoop(0x1cad608) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x1d87fe4 sp=0x1d87fa4 pc=0x4175a4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2Transport).newClientConn.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x1d87fec sp=0x1d87fe4 pc=0x4105f0 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d87fec sp=0x1d87fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*http2Transport).newClientConn in goroutine 69 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 103 gp=0x1d9bd48 m=nil [IO wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f928, 0xb57c3a08, 0x2, 0x2, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1e30938 sp=0x1e30924 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.netpollblock(0xb57c39f8, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x1e30950 sp=0x1e30938 pc=0x540f0 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.runtime_pollWait(0xb57c39f8, 0x72) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x1e30964 sp=0x1e30950 pc=0x8eba8 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).wait(0x1dbb738, 0x72, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x1e30978 sp=0x1e30964 pc=0x108108 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*pollDesc).waitRead(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 19:47:32 volumio-wk go-librespot[1133]: internal/poll.(*FD).Read(0x1dbb720, {0x1e5e000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x1e309c0 sp=0x1e30978 pc=0x1092f4 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*netFD).Read(0x1dbb720, {0x1e5e000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x1e309ec sp=0x1e309c0 pc=0x2a0610 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*conn).Read(0x1dbcdb0, {0x1e5e000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x1e30a18 sp=0x1e309ec pc=0x2b07f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net.(*TCPConn).Read(0x1dbcdb0, {0x1e5e000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x44 fp=0x1e30a38 sp=0x1e30a18 pc=0x2c3a44 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*atLeastReader).Read(0x1fed820, {0x1e5e000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x1e30a64 sp=0x1e30a38 pc=0x386018 May 08 19:47:32 volumio-wk go-librespot[1133]: bytes.(*Buffer).ReadFrom(0x1d59a4c, {0x723a98, 0x1fed820}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x1e30aa0 sp=0x1e30a64 pc=0x136d6c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readFromUntil(0x1d598c8, {0x722604, 0x1dbcdb0}, 0x5) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x1e30ac8 sp=0x1e30aa0 pc=0x386274 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1d598c8, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x1e30c2c sp=0x1e30ac8 pc=0x383974 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1d598c8, {0x1d88000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1e30c5c sp=0x1e30c2c pc=0x3897e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*readWriteCloserBody).Read(0x1e44350, {0x1d88000, 0x1000, 0x1000}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2429 +0xec fp=0x1e30c7c sp=0x1e30c5c pc=0x4538c0 May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).fill(0x1d76330) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x1e30ca0 sp=0x1e30c7c pc=0x15a4b8 May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).ReadByte(0x1d76330) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x28 fp=0x1e30cac sp=0x1e30ca0 pc=0x15ad3c May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.readFrameHeader(0x1d76330, {0x1cf7938, 0x8, 0x8}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x1e30cec sp=0x1e30cac pc=0x4771e0 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x1cf7908, {0x725688, 0xad3b20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x1e30dac sp=0x1e30cec pc=0x479e44 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).readLoop(0x1cf7908, {0x725688, 0xad3b20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x1e30e70 sp=0x1e30dac pc=0x47992c May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).reader(0x1cf7908, {0x725688, 0xad3b20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x1e30efc sp=0x1e30e70 pc=0x47ab40 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).Reader(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 May 08 19:47:32 volumio-wk go-librespot[1133]: nhooyr.io/websocket.(*Conn).Read(0x1cf7908, {0x725688, 0xad3b20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x1e30f24 sp=0x1e30efc pc=0x479210 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/dealer.(*Dealer).recvLoop(0x1dbf0e8) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:153 +0x58 fp=0x1e30fe4 sp=0x1e30f24 pc=0x4b8a14 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x28 fp=0x1e30fec sp=0x1e30fe4 pc=0x4ba26c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1e30fec sp=0x1e30fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1 in goroutine 101 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x60 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 115 gp=0x1f4c008 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c52de4 sp=0x1c52dd0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1c52f78, 0x1c52ebc, 0x0, 0x0, 0x4, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1c52e84 sp=0x1c52de4 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).readLoop(0x1fd1298) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2261 +0xc68 fp=0x1c52fe4 sp=0x1c52e84 pc=0x4529f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConn.gowrap2() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x28 fp=0x1c52fec sp=0x1c52fe4 pc=0x45083c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c52fec sp=0x1c52fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*Transport).dialConn in goroutine 110 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x13f4 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 116 gp=0x1f4c128 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1d82eb0 sp=0x1d82e9c pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1d82fac, 0x1d82f78, 0x0, 0x0, 0x2, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1d82f50 sp=0x1d82eb0 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).writeLoop(0x1fd1298) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2444 +0xd0 fp=0x1d82fe4 sp=0x1d82f50 pc=0x4539dc May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConn.gowrap3() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x28 fp=0x1d82fec sp=0x1d82fe4 pc=0x4507e8 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d82fec sp=0x1d82fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*Transport).dialConn in goroutine 110 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x1444 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 149 gp=0x1f4c248 m=nil [sync.Cond.Wait]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1fe36f0, 0x14, 0x4, 0x3) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1c40720 sp=0x1c4070c pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:32 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1fe36e8, 0x13) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x1c4074c sp=0x1c40720 pc=0x90a94 May 08 19:47:32 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1fe36e0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x1c40770 sp=0x1c4074c pc=0x9cc44 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/output.(*RingBuffer[...]).PutWait(0x726460, {0x223d800, 0x1c2, 0x1c2}) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/output/ring_buffer.go:50 +0x8c fp=0x1c40798 sp=0x1c40770 pc=0x49df68 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/output.(*output).readLoop(0x1e968c0) May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:252 +0xb8 fp=0x1c407d0 sp=0x1c40798 pc=0x49abd4 May 08 19:47:32 volumio-wk go-librespot[1133]: go-librespot/output.newOutput.func2() May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:93 +0x20 fp=0x1c407ec sp=0x1c407d0 pc=0x498ec4 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1c407ec sp=0x1c407ec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by go-librespot/output.newOutput in goroutine 99 May 08 19:47:32 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:92 +0x3d8 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 380 gp=0x1f4c6c8 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1de3df4 sp=0x1de3de0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1de3f30, 0x1de3ebc, 0x0, 0x0, 0x6, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1de3e94 sp=0x1de3df4 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2clientStream).writeRequest(0x1cf9b28, 0x1ed9048) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8522 +0xa90 fp=0x1de3fcc sp=0x1de3e94 pc=0x413b5c May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2clientStream).doRequest(0x1cf9b28, 0x1ed9048) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8384 +0x24 fp=0x1de3fe0 sp=0x1de3fcc pc=0x4130a0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*http2ClientConn).RoundTrip.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8290 +0x30 fp=0x1de3fec sp=0x1de3fe0 pc=0x413050 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1de3fec sp=0x1de3fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*http2ClientConn).RoundTrip in goroutine 101 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8290 +0x338 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 142 gp=0x1f4cc68 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1dddde4 sp=0x1ddddd0 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1dddf78, 0x1dddebc, 0x0, 0x0, 0x4, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1ddde84 sp=0x1dddde4 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).readLoop(0x1fd0378) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2261 +0xc68 fp=0x1dddfe4 sp=0x1ddde84 pc=0x4529f0 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConn.gowrap2() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x28 fp=0x1dddfec sp=0x1dddfe4 pc=0x45083c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1dddfec sp=0x1dddfec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*Transport).dialConn in goroutine 128 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x13f4 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 143 gp=0x1f4cd88 m=nil [select]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1ddfeb0 sp=0x1ddfe9c pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.selectgo(0x1ddffac, 0x1ddff78, 0x0, 0x0, 0x2, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1ddff50 sp=0x1ddfeb0 pc=0x705e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).writeLoop(0x1fd0378) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2444 +0xd0 fp=0x1ddffe4 sp=0x1ddff50 pc=0x4539dc May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConn.gowrap3() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x28 fp=0x1ddffec sp=0x1ddffe4 pc=0x4507e8 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1ddffec sp=0x1ddffec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*Transport).dialConn in goroutine 128 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x1444 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 379 gp=0x25b8b48 m=nil [runnable]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.asyncPreempt2() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt.go:307 +0x38 fp=0x1de08f4 sp=0x1de08e8 pc=0x5abbc May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.asyncPreempt() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt_arm.s:44 +0x98 fp=0x1de09b0 sp=0x1de08f4 pc=0x93fb4 May 08 19:47:32 volumio-wk go-librespot[1133]: math/bits.Mul64(0xf83b98f29d058, 0x4cbaeef96c7ae) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/math/bits/bits.go:482 +0x34 fp=0x1de09bc sp=0x1de09b4 pc=0xc4c00 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/internal/edwards25519/field.mul64(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/edwards25519/field/fe_generic.go:17 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/internal/edwards25519/field.feSquareGeneric(0x1de0b24, 0x1de0b24) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/edwards25519/field/fe_generic.go:213 +0x1e0 fp=0x1de0a9c sp=0x1de09bc pc=0x31b4c4 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/internal/edwards25519/field.feSquare(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/edwards25519/field/fe_amd64_noasm.go:11 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/internal/edwards25519/field.(*Element).Square(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/edwards25519/field/fe.go:309 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/ecdh.x25519ScalarMult({0x1f7f9a0, 0x20, 0x20}, {0x1f7f980, 0x20, 0x20}, {0x1de0c48, 0x20, 0x20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/ecdh/x25519.go:121 +0x2f4 fp=0x1de0c20 sp=0x1de0a9c pc=0x31cf38 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/ecdh.(*x25519Curve).privateKeyToPublicKey(0xad3b20, 0x1c16480) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/ecdh/x25519.go:63 +0x140 fp=0x1de0c74 sp=0x1de0c20 pc=0x31c92c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).makeClientHello.(*PrivateKey).PublicKey.func1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/ecdh/ecdh.go:178 +0x3c fp=0x1de0ca8 sp=0x1de0c74 pc=0x38c2a8 May 08 19:47:32 volumio-wk go-librespot[1133]: sync.(*Once).doSlow(0x1c1649c, 0x1de0d84) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/once.go:74 +0xc8 fp=0x1de0cd4 sp=0x1de0ca8 pc=0x9f05c May 08 19:47:32 volumio-wk go-librespot[1133]: sync.(*Once).Do(0x1c1649c, 0x1de0d84) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/once.go:65 +0x40 fp=0x1de0ce0 sp=0x1de0cd4 pc=0x9ef84 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/ecdh.(*PrivateKey).PublicKey(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/ecdh/ecdh.go:162 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).makeClientHello(0x1e7cb48) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client.go:156 +0xb6c fp=0x1de0d8c sp=0x1de0ce0 pc=0x38be08 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).clientHandshake(0x1e7cb48, {0x7256c8, 0x1c16450}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client.go:182 +0x78 fp=0x1de0ea0 sp=0x1de0d8c pc=0x38c4a0 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).clientHandshake-fm({0x7256c8, 0x1c16450}) May 08 19:47:32 volumio-wk go-librespot[1133]: :1 +0x38 fp=0x1de0eb8 sp=0x1de0ea0 pc=0x3c4438 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).handshakeContext(0x1e7cb48, {0x725688, 0xad3b20}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1553 +0x338 fp=0x1de0fb0 sp=0x1de0eb8 pc=0x38a30c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).HandshakeContext(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1493 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).addTLS.func2() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1573 +0x78 fp=0x1de0fec sp=0x1de0fb0 pc=0x44e9a8 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1de0fec sp=0x1de0fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*persistConn).addTLS in goroutine 264 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1569 +0x2e4 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 264 gp=0x25b8c68 m=nil [chan receive]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.gopark(0x68f7c8, 0x1f80e70, 0xe, 0x7, 0x2) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1de1b64 sp=0x1de1b50 pc=0x5c82c May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv(0x1f80e40, 0x1de1ca4, 0x1) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x1de1ba0 sp=0x1de1b64 pc=0x1fdc4 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.chanrecv1(0x1f80e40, 0x1de1ca4) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:442 +0x20 fp=0x1de1bb4 sp=0x1de1ba0 pc=0x1f8e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).addTLS(0x1fd0008, {0x725688, 0xad3b20}, {0x1f7f680, 0x18}, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1579 +0x308 fp=0x1de1cb0 sp=0x1de1bb4 pc=0x44e704 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConn(0xa67ab0, {0x725688, 0xad3b20}, {{}, 0x0, {0x1d0d130, 0x5}, {0x1f7f680, 0x1c}, 0x0}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1658 +0x8b0 fp=0x1de1f48 sp=0x1de1cb0 pc=0x44f340 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).dialConnFor(0xa67ab0, 0x1ff29c0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1485 +0x84 fp=0x1de1fe0 sp=0x1de1f48 pc=0x44de50 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*Transport).queueForDial.gowrap1() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1449 +0x30 fp=0x1de1fec sp=0x1de1fe0 pc=0x44dda0 May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1de1fec sp=0x1de1fec pc=0x9346c May 08 19:47:32 volumio-wk go-librespot[1133]: created by net/http.(*Transport).queueForDial in goroutine 237 May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1449 +0x98 May 08 19:47:32 volumio-wk go-librespot[1133]: goroutine 241 gp=0x25ce248 m=nil [runnable]: May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.asyncPreempt2() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt.go:307 +0x38 fp=0x1dde7c4 sp=0x1dde7b8 pc=0x5abbc May 08 19:47:32 volumio-wk go-librespot[1133]: runtime.asyncPreempt() May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt_arm.s:44 +0x98 fp=0x1dde880 sp=0x1dde7c4 pc=0x93fb4 May 08 19:47:32 volumio-wk go-librespot[1133]: encoding/binary.littleEndian.Uint64(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/encoding/binary/binary.go:107 May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.updateGeneric(0x1ddea14, {0x1ee601b, 0x4000, 0x5fe5}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:159 +0x370 fp=0x1dde958 sp=0x1dde884 pc=0x37827c May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.(*macGeneric).Write(0x1ddea14, {0x1ee601b, 0x4001, 0x5fe5}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:74 +0x15c fp=0x1dde984 sp=0x1dde958 pc=0x377b00 May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.(*MAC).Write(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/poly1305.go:80 May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.writeWithPadding(0x1ddea14, {0x1ee601b, 0x4001, 0x5fe5}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:16 +0x44 fp=0x1dde9b4 sp=0x1dde984 pc=0x378bec May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).openGeneric(0x202c320, {0x1ee601b, 0x0, 0x5fe5}, {0x200e018, 0xc, 0xc}, {0x1ee601b, 0x4011, 0x5fe5}, ...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:64 +0x1ac fp=0x1ddeb1c sp=0x1dde9b4 pc=0x379304 May 08 19:47:32 volumio-wk sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).open(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_noasm.go:14 May 08 19:47:32 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).Open(0x202c320, {0x1ee601b, 0x0, 0x5fe5}, {0x200e018, 0xc, 0xc}, {0x1ee601b, 0x4011, 0x5fe5}, ...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305.go:82 +0xc4 fp=0x1ddeb68 sp=0x1ddeb1c pc=0x378afc May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*xorNonceAEAD).Open(0x200e018, {0x1ee601b, 0x0, 0x5fe5}, {0x1e7c0f8, 0x8, 0x8}, {0x1ee601b, 0x4011, 0x5fe5}, ...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/cipher_suites.go:519 +0xc0 fp=0x1ddebb4 sp=0x1ddeb68 pc=0x37dfa4 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*halfConn).decrypt(0x1e7c0d4, {0x1ee6016, 0x4016, 0x5fea}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:380 +0x4bc fp=0x1ddec60 sp=0x1ddebb4 pc=0x382678 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1e7c008, 0x0) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:686 +0xbfc fp=0x1ddedc4 sp=0x1ddec60 pc=0x38443c May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:32 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1e7c008, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1ddedf4 sp=0x1ddedc4 pc=0x3897e4 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*persistConn).Read(0x1fd0378, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1977 +0x16c fp=0x1ddee28 sp=0x1ddedf4 pc=0x45138c May 08 19:47:32 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x20744e0, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:227 +0x12c fp=0x1ddee4c sp=0x1ddee28 pc=0x15aa5c May 08 19:47:32 volumio-wk go-librespot[1133]: io.(*LimitedReader).Read(0x1feca20, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:479 +0xc4 fp=0x1ddee6c sp=0x1ddee4c pc=0x102878 May 08 19:47:32 volumio-wk go-librespot[1133]: net/http.(*body).readLocked(0x1c164b0, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:32 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:840 +0x4c fp=0x1ddee98 sp=0x1ddee6c pc=0x446748 May 08 19:47:32 volumio-wk sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*body).Read(0x1c164b0, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:832 +0xe8 fp=0x1ddeecc sp=0x1ddee98 pc=0x446654 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*bodyEOFSignal).Read(0x1c164e0, {0x2025f84, 0x207c, 0x207c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2833 +0xc0 fp=0x1ddef08 sp=0x1ddeecc pc=0x455570 May 08 19:47:33 volumio-wk go-librespot[1133]: io.ReadAll({0x72276c, 0x1c164e0}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:712 +0x84 fp=0x1ddef44 sp=0x1ddef08 pc=0x1030e8 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:169 +0x140 fp=0x1ddefc4 sp=0x1ddef44 pc=0x492724 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1ddefe4 sp=0x1ddefc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1ddefec sp=0x1ddefe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1ddefec sp=0x1ddefec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 240 gp=0x25ce368 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1d3fcb0, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x25c8ef4 sp=0x25c8ee0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1d3fca8, 0x0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x25c8f20 sp=0x25c8ef4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1d3fca0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x25c8f44 sp=0x25c8f20 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x25c8fc4 sp=0x25c8f44 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x25c8fe4 sp=0x25c8fc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x25c8fec sp=0x25c8fe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x25c8fec sp=0x25c8fec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 239 gp=0x25ce488 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1d3fbd0, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x25c96f4 sp=0x25c96e0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1d3fbc8, 0x0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x25c9720 sp=0x25c96f4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1d3fbc0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x25c9744 sp=0x25c9720 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x25c97c4 sp=0x25c9744 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x25c97e4 sp=0x25c97c4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x25c97ec sp=0x25c97e4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x25c97ec sp=0x25c97ec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 238 gp=0x25ce5a8 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1c14010, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x25c9ef4 sp=0x25c9ee0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1c14008, 0x0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x25c9f20 sp=0x25c9ef4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1c14000) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x25c9f44 sp=0x25c9f20 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x25c9fc4 sp=0x25c9f44 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x25c9fe4 sp=0x25c9fc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x25c9fec sp=0x25c9fe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x25c9fec sp=0x25c9fec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 237 gp=0x25ce6c8 m=nil [select]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1ddc88c sp=0x1ddc878 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.selectgo(0x1ddc9c4, 0x1ddc96c, 0x0, 0x0, 0x4, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x1ddc92c sp=0x1ddc88c pc=0x705e4 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Transport).getConn(0xa67ab0, 0x1df5660, {{}, 0x0, {0x1d0d130, 0x5}, {0x1f7f680, 0x1c}, 0x0}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1406 +0x4a0 fp=0x1ddca5c sp=0x1ddc92c pc=0x44d438 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Transport).roundTrip(0xa67ab0, 0x1ed8a08) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:595 +0x778 fp=0x1ddcb78 sp=0x1ddca5c pc=0x449410 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Transport).RoundTrip(0xa67ab0, 0x1ed8a08) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/roundtrip.go:17 +0x24 fp=0x1ddcb90 sp=0x1ddcb78 pc=0x42d82c May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.send(0x1ed8a08, {0x72294c, 0xa67ab0}, {0x0, 0x0, 0x0}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:259 +0x540 fp=0x1ddccbc sp=0x1ddcb90 pc=0x3e8554 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Client).send(0x1d3f000, 0x1ed8a08, {0x0, 0x0, 0x0}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:180 +0x98 fp=0x1ddcd00 sp=0x1ddccbc pc=0x3e7e48 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Client).do(0x1d3f000, 0x1ed8a08) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:724 +0x8bc fp=0x1ddce10 sp=0x1ddcd00 pc=0x3ea248 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*Client).Do(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:590 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).downloadChunk.func1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:111 +0x290 fp=0x1ddce6c sp=0x1ddce10 pc=0x4924c8 May 08 19:47:33 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x1ddcf38, {0x724ee8, 0x1d7d4a8}, 0x0, {0x0, 0x0}) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:88 +0xf0 fp=0x1ddceec sp=0x1ddce6c pc=0x496294 May 08 19:47:33 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.RetryNotifyWithData[...](...) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:54 May 08 19:47:33 volumio-wk go-librespot[1133]: github.com/cenkalti/backoff/v4.RetryWithData[...](0x25ca738, {0x724ee8, 0x1d7d4a8}) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:43 +0x54 fp=0x1ddcf18 sp=0x1ddceec pc=0x49617c May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).downloadChunk(0x1f50120, 0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:110 +0x84 fp=0x1ddcf44 sp=0x1ddcf18 pc=0x4921f8 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:153 +0xc8 fp=0x1ddcfc4 sp=0x1ddcf44 pc=0x4926ac May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1ddcfe4 sp=0x1ddcfc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1ddcfec sp=0x1ddcfe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1ddcfec sp=0x1ddcfec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 236 gp=0x25ce7e8 m=nil [runnable]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.asyncPreempt2() May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt.go:307 +0x38 fp=0x1d80798 sp=0x1d8078c pc=0x5abbc May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.asyncPreempt() May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt_arm.s:44 +0x98 fp=0x1d80854 sp=0x1d80798 pc=0x93fb4 May 08 19:47:33 volumio-wk go-librespot[1133]: math/bits.Mul64(0xef8f237512d7d9e4, 0x5688c0d39d12c) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/math/bits/bits.go:480 +0x2c fp=0x1d80860 sp=0x1d80858 pc=0xc4bf8 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.bitsMul64(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/bits_go1.13.go:20 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.mul64(0xef8f237512d7d9e4, 0x5688c0d39d12c) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:117 +0x38 fp=0x1d80884 sp=0x1d80860 pc=0x377e14 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.updateGeneric(0x1d80a14, {0x1fa201b, 0x4000, 0x5fe5}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:200 +0x6b0 fp=0x1d80958 sp=0x1d80884 pc=0x3785bc May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.(*macGeneric).Write(0x1d80a14, {0x1fa201b, 0x4001, 0x5fe5}) May 08 19:47:33 volumio-wk volumio[755]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:74 +0x15c fp=0x1d80984 sp=0x1d80958 pc=0x377b00 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/internal/poly1305.(*MAC).Write(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/poly1305.go:80 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.writeWithPadding(0x1d80a14, {0x1fa201b, 0x4001, 0x5fe5}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:16 +0x44 fp=0x1d809b4 sp=0x1d80984 pc=0x378bec May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).openGeneric(0x1f7ece0, {0x1fa201b, 0x0, 0x5fe5}, {0x1e93a10, 0xc, 0xc}, {0x1fa201b, 0x4011, 0x5fe5}, ...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:64 +0x1ac fp=0x1d80b1c sp=0x1d809b4 pc=0x379304 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).open(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_noasm.go:14 May 08 19:47:33 volumio-wk go-librespot[1133]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).Open(0x1f7ece0, {0x1fa201b, 0x0, 0x5fe5}, {0x1e93a10, 0xc, 0xc}, {0x1fa201b, 0x4011, 0x5fe5}, ...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305.go:82 +0xc4 fp=0x1d80b68 sp=0x1d80b1c pc=0x378afc May 08 19:47:33 volumio-wk go-librespot[1133]: crypto/tls.(*xorNonceAEAD).Open(0x1e93a10, {0x1fa201b, 0x0, 0x5fe5}, {0x1e7d538, 0x8, 0x8}, {0x1fa201b, 0x4011, 0x5fe5}, ...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/cipher_suites.go:519 +0xc0 fp=0x1d80bb4 sp=0x1d80b68 pc=0x37dfa4 May 08 19:47:33 volumio-wk go-librespot[1133]: crypto/tls.(*halfConn).decrypt(0x1e7d514, {0x1fa2016, 0x4016, 0x5fea}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:380 +0x4bc fp=0x1d80c60 sp=0x1d80bb4 pc=0x382678 May 08 19:47:33 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecordOrCCS(0x1e7d448, 0x0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:686 +0xbfc fp=0x1d80dc4 sp=0x1d80c60 pc=0x38443c May 08 19:47:33 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).readRecord(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 May 08 19:47:33 volumio-wk go-librespot[1133]: crypto/tls.(*Conn).Read(0x1e7d448, {0x1f53000, 0x1000, 0x1000}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x1d80df4 sp=0x1d80dc4 pc=0x3897e4 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*persistConn).Read(0x1fd1298, {0x1f53000, 0x1000, 0x1000}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1977 +0x16c fp=0x1d80e28 sp=0x1d80df4 pc=0x45138c May 08 19:47:33 volumio-wk go-librespot[1133]: bufio.(*Reader).Read(0x1f50ba0, {0x212d784, 0x87c, 0x87c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x1d80e4c sp=0x1d80e28 pc=0x15ab44 May 08 19:47:33 volumio-wk go-librespot[1133]: io.(*LimitedReader).Read(0x1fec980, {0x212d784, 0x87c, 0x87c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:479 +0xc4 fp=0x1d80e6c sp=0x1d80e4c pc=0x102878 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*body).readLocked(0x1c163f0, {0x212d784, 0x87c, 0x87c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:840 +0x4c fp=0x1d80e98 sp=0x1d80e6c pc=0x446748 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*body).Read(0x1c163f0, {0x212d784, 0x87c, 0x87c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:832 +0xe8 fp=0x1d80ecc sp=0x1d80e98 pc=0x446654 May 08 19:47:33 volumio-wk go-librespot[1133]: net/http.(*bodyEOFSignal).Read(0x1c16420, {0x212d784, 0x87c, 0x87c}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2833 +0xc0 fp=0x1d80f08 sp=0x1d80ecc pc=0x455570 May 08 19:47:33 volumio-wk go-librespot[1133]: io.ReadAll({0x72276c, 0x1c16420}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:712 +0x84 fp=0x1d80f44 sp=0x1d80f08 pc=0x1030e8 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:169 +0x140 fp=0x1d80fc4 sp=0x1d80f44 pc=0x492724 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1d80fe4 sp=0x1d80fc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1d80fec sp=0x1d80fe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1d80fec sp=0x1d80fec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 375 gp=0x1d2f448 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1d3fbd0, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1efe6f4 sp=0x1efe6e0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1d3fbc8, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x1efe720 sp=0x1efe6f4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1d3fbc0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x1efe744 sp=0x1efe720 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x1efe7c4 sp=0x1efe744 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1efe7e4 sp=0x1efe7c4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1efe7ec sp=0x1efe7e4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1efe7ec sp=0x1efe7ec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 376 gp=0x1d2f568 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1d3fcb0, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1efeef4 sp=0x1efeee0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1d3fca8, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x1efef20 sp=0x1efeef4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1d3fca0) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x1efef44 sp=0x1efef20 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x1efefc4 sp=0x1efef44 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1efefe4 sp=0x1efefc4 pc=0x492db4 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1efefec sp=0x1efefe4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1efefec sp=0x1efefec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: goroutine 377 gp=0x1d2f688 m=nil [sync.Cond.Wait]: May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.gopark(0x68f938, 0x1c14010, 0x14, 0x4, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x1eff6f4 sp=0x1eff6e0 pc=0x5c82c May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goparkunlock(...) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.runtime_notifyListWait(0x1c14008, 0x1) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x1eff720 sp=0x1eff6f4 pc=0x90a94 May 08 19:47:33 volumio-wk go-librespot[1133]: sync.(*Cond).Wait(0x1c14000) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x1eff744 sp=0x1eff720 pc=0x9cc44 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x1f50120, 0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x1eff7c4 sp=0x1eff744 pc=0x492b94 May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x1eff7e4 sp=0x1eff7c4 pc=0x492db4 May 08 19:47:33 volumio-wk sudo[1242]: pam_unix(sudo:session): session closed for user root May 08 19:47:33 volumio-wk go-librespot[1133]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x1eff7ec sp=0x1eff7e4 pc=0x492d64 May 08 19:47:33 volumio-wk go-librespot[1133]: runtime.goexit({}) May 08 19:47:33 volumio-wk go-librespot[1133]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x1eff7ec sp=0x1eff7ec pc=0x9346c May 08 19:47:33 volumio-wk go-librespot[1133]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 160 May 08 19:47:33 volumio-wk go-librespot[1133]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 May 08 19:47:33 volumio-wk go-librespot[1133]: Aborted May 08 19:47:33 volumio-wk systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a May 08 19:47:33 volumio-wk systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 19:47:33 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:47:33] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 08 19:47:34 volumio-wk volumio[755]: info: Getting Spotify volume May 08 19:47:34 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 19:47:34 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 19:47:34 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 08 19:47:35 volumio-wk volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 08 19:47:35 volumio-wk volumio[755]: Upnp client error: Error: This socket has been ended by the other party May 08 19:47:36 volumio-wk volumio[755]: error: MPD error: The expression evaluated to a falsy value: May 08 19:47:36 volumio-wk volumio[755]: assert.ok(self.idling) May 08 19:47:36 volumio-wk volumio[755]: error: The expression evaluated to a falsy value: May 08 19:47:36 volumio-wk volumio[755]: assert.ok(self.idling) May 08 19:47:36 volumio-wk volumio[755]: Upnp client error: Error: This socket has been ended by the other party May 08 19:47:36 volumio-wk volumio[755]: Upnp client error: Error: This socket has been ended by the other party May 08 19:47:36 volumio-wk systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 08 19:47:36 volumio-wk systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. May 08 19:47:36 volumio-wk systemd[1]: Stopped go-librespot Daemon. May 08 19:47:36 volumio-wk volumio[755]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6Dc2tCivms1s2X9myWe4ni","play_origin":"playlist/ondemand"}} May 08 19:47:36 volumio-wk systemd[1]: Started go-librespot Daemon. May 08 19:47:36 volumio-wk go-librespot[1268]: Librespot-go daemon starting... May 08 19:47:36 volumio-wk volumio[755]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6Dc2tCivms1s2X9myWe4ni","name":"Tuyo (Narcos Theme) - A Netflix Original Series Soundtrack","artist_names":["Rodrigo Amarante"],"album_name":"Tuyo (Narcos Theme) [A Netflix Original Series Soundtrack]","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0224ba46bcc2ba65b670ff3e6c","position":73222,"duration":89293,"release_date":"year:2015 month:9 day:18","track_number":1,"disc_number":1}} May 08 19:47:36 volumio-wk volumio[755]: SPOTIFY: received: {"type":"active","data":null} May 08 19:47:36 volumio-wk volumio[755]: info: Aligning Spotify Volume to Volumio Volume May 08 19:47:36 volumio-wk volumio[755]: info: CoreCommandRouter::volumioGetState May 08 19:47:36 volumio-wk volumio[755]: info: CorePlayQueue::getTrack 0 May 08 19:47:36 volumio-wk volumio[755]: info: Setting Spotify Volume from Volumio: 84 May 08 19:47:36 volumio-wk volumio[755]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6Dc2tCivms1s2X9myWe4ni","play_origin":"playlist/ondemand"}} May 08 19:47:36 volumio-wk volumio[755]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 19:47:36 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:36+02:00" level=info msg="generated new device id: 07856ea40583c5640b40b50699866dde8e58b2d6" May 08 19:47:36 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:36+02:00" level=debug msg="stored credentials found for 8qfabslguer3f5szkbjv982c2" May 08 19:47:37 volumio-wk volumio[755]: TypeError: Cannot read property 'service' of undefined May 08 19:47:37 volumio-wk volumio[755]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) May 08 19:47:37 volumio-wk volumio[755]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) May 08 19:47:37 volumio-wk volumio[755]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) May 08 19:47:37 volumio-wk volumio[755]: at WebSocket.emit (events.js:315:20) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.emit (events.js:315:20) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 08 19:47:37 volumio-wk volumio[755]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 08 19:47:37 volumio-wk volumio[755]: at writeOrBuffer (internal/streams/writable.js:358:12) May 08 19:47:37 volumio-wk volumio[755]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 08 19:47:37 volumio-wk volumio[755]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 08 19:47:37 volumio-wk volumio[755]: at Socket.emit (events.js:315:20) May 08 19:47:37 volumio-wk volumio[755]: at addChunk (internal/streams/readable.js:309:12) May 08 19:47:37 volumio-wk volumio[755]: at readableAddChunk (internal/streams/readable.js:284:9) May 08 19:47:37 volumio-wk volumio[755]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 19:47:38 volumio-wk volumio-remote-updater[389]: [2025-05-08 19:47:38] [connect] Successful connection May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+02:00" level=debug msg="zeroconf server listening on port 46571" May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+02:00" level=debug msg="obtained new client token: AADakEN3AZ9vPF1+uU2yi/OIiNoX5AX5BzeUs85HUfW80twI5QGpeFSY6hO+ut9S5NYCuUtvwoQNQgi7fBPzUyrp4lNmhGG8+vjCIAZ6kj59rDzd9gFhYOLdj2N54l5H53NmuLRH84XJr/1b9VXVJQdWyoNhjM6+Or0qeoBCQelfVjhQNHqz67cW3zAnbfzrJjManWIgKpaRVB+mj3KgSR24avnWZtVzUHOJZJvUva/9TKC82U2jzjqevvjoew==" May 08 19:47:39 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:39+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" May 08 19:47:40 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:40+02:00" level=info msg="connected to ap-gew4.spotify.com:443" May 08 19:47:40 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:40+02:00" level=debug msg="completed keyexchange" May 08 19:47:40 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:40+02:00" level=debug msg="completed challenge" May 08 19:47:40 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:40+02:00" level=debug msg="authenticated as 8qfabslguer3f5szkbjv982c2" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="authenticated as 8qfabslguer3f5szkbjv982c2" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="dealer connection opened" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="initializing zeroconf session, username: 8qfabslguer3f5szkbjv982c2" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="received connection id: NjUwYWEzYmItMGQ0Yi00ZTA1LWE1ZjktYWZjMmFkNGMzODIzK2RlYWxlcit0Y3A6Ly8wYWNhNTg1Mi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArN0M1NjZDRUZGMUJFQjE3NTBCQkM4QUNCMjk0NEY0REM1N0ZDNUFGOTgxRDEzMkYwQzBGMjNGMjExNzFDOEE4Mg==" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="put connect state because NEW_DEVICE" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 08 19:47:41 volumio-wk go-librespot[1268]: time="2025-05-08T19:47:41+02:00" level=debug msg="autoplay enabled: false" May 08 19:47:46 volumio-wk sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-08 19:46 May 08 19:47:46 volumio-wk sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"