-- Logs begin at Thu 2019-02-14 12:12:00 EET, end at Thu 2024-11-28 23:11:25 EET. -- Nov 28 23:10:10 volumio systemd-timedated[974]: Changed local time to Thu Nov 28 23:10:10 2024 Nov 28 23:10:10 volumio sudo[972]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:10 volumio volumio-time-update[573]: volumio-time-update-util: System time updated successfully. Nov 28 23:10:10 volumio systemd[1]: Starting Daily apt download activities... Nov 28 23:10:10 volumio systemd[1]: Starting Daily man-db regeneration... Nov 28 23:10:10 volumio systemd[1]: Started Volumio Time Update Utility. Nov 28 23:10:10 volumio systemd[1]: Reached target Multi-User System. Nov 28 23:10:10 volumio systemd[1]: Reached target Graphical Interface. Nov 28 23:10:10 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 28 23:10:10 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 28 23:10:10 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 28 23:10:10 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:10 volumio volumio[931]: info: ----- Volumio3 ---- Nov 28 23:10:10 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:10 volumio volumio[931]: info: ----- System startup ---- Nov 28 23:10:10 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:10 volumio systemd[1]: man-db.service: Succeeded. Nov 28 23:10:10 volumio systemd[1]: Started Daily man-db regeneration. Nov 28 23:10:13 volumio volumio[931]: info: MYVOLUMIO Environment detected Nov 28 23:10:13 volumio volumio[931]: info: Plugin folders cleanup Nov 28 23:10:13 volumio volumio[931]: info: Scanning into folder /volumio/app/plugins/ Nov 28 23:10:13 volumio volumio[931]: info: Scanning category audio_interface Nov 28 23:10:13 volumio volumio[931]: info: Scanning category miscellanea Nov 28 23:10:13 volumio volumio[931]: info: Scanning category music_service Nov 28 23:10:13 volumio volumio[931]: info: Scanning category plugins.json Nov 28 23:10:13 volumio volumio[931]: info: Scanning category system_controller Nov 28 23:10:13 volumio volumio[931]: info: Scanning category user_interface Nov 28 23:10:13 volumio volumio[931]: info: Scanning into folder /data/plugins/ Nov 28 23:10:13 volumio volumio[931]: info: Scanning category music_service Nov 28 23:10:13 volumio volumio[931]: info: Scanning category user_interface Nov 28 23:10:13 volumio volumio[931]: info: Plugin folders cleanup completed Nov 28 23:10:13 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:13 volumio volumio[931]: info: ----- Core plugins startup ---- Nov 28 23:10:13 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:13 volumio volumio[931]: info: Loading plugins from folder /volumio/app/plugins/ Nov 28 23:10:13 volumio volumio[931]: info: Adding plugin upnp to MyMusic Plugins Nov 28 23:10:13 volumio volumio[931]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 28 23:10:13 volumio volumio[931]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 28 23:10:13 volumio volumio[931]: info: Loading plugins from folder /data/plugins/ Nov 28 23:10:13 volumio volumio[931]: info: Loading plugin "system"... Nov 28 23:10:13 volumio volumio[931]: info: Loading plugin "appearance"... Nov 28 23:10:16 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Nov 28 23:10:16 volumio volumio-remote-updater[543]: [2024-11-28 23:10:16] [connect] Successful connection Nov 28 23:10:19 volumio volumio[931]: info: Loading plugin "network"... Nov 28 23:10:19 volumio volumio[931]: info: Refreshing Cached IP Addresses Nov 28 23:10:19 volumio sudo[1050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 28 23:10:19 volumio sudo[1046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 28 23:10:19 volumio sudo[1050]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:19 volumio sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:19 volumio volumio[931]: info: Loading plugin "services"... Nov 28 23:10:19 volumio volumio[931]: info: Loading plugin "alsa_controller"... Nov 28 23:10:19 volumio sudo[1050]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:19 volumio sudo[1061]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 28 23:10:19 volumio sudo[1061]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:19 volumio sudo[1046]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:19 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 23:10:19 volumio volumio[931]: info: Loading plugin "wizard"... Nov 28 23:10:19 volumio volumio[931]: info: Loading plugin "networkfs"... Nov 28 23:10:20 volumio systemd[1]: apt-daily.service: Succeeded. Nov 28 23:10:20 volumio systemd[1]: Started Daily apt download activities. Nov 28 23:10:20 volumio volumio[931]: info: Starting Udev Watcher for removable devices Nov 28 23:10:20 volumio volumio[931]: info: Ignoring mount for partition: boot Nov 28 23:10:20 volumio volumio[931]: info: Ignoring mount for partition: volumio Nov 28 23:10:20 volumio volumio[931]: info: Ignoring mount for partition: volumio_data Nov 28 23:10:20 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 23:10:20 volumio volumio[931]: info: Loading plugin "volumio_command_line_client"... Nov 28 23:10:20 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Nov 28 23:10:20 volumio volumio[931]: info: Loading plugin "upnp"... Nov 28 23:10:20 volumio volumio[931]: info: [1732828220196] Starting Upmpd Daemon Nov 28 23:10:20 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 23:10:20 volumio volumio[931]: info: Loading plugin "my_music"... Nov 28 23:10:20 volumio volumio[931]: info: Loading plugin "mpd"... Nov 28 23:10:21 volumio volumio[931]: info: Loading plugin "upnp_browser"... Nov 28 23:10:22 volumio volumio[931]: info: Loading plugin "alarm-clock"... Nov 28 23:10:22 volumio volumio[931]: info: Loading plugin "airplay_emulation"... Nov 28 23:10:22 volumio volumio[931]: info: Starting Shairport Sync Nov 28 23:10:22 volumio volumio[931]: info: Loading plugin "last_100"... Nov 28 23:10:22 volumio volumio[931]: info: Loading plugin "webradio"... Nov 28 23:10:23 volumio volumio[931]: info: Loading plugin "i2s_dacs"... Nov 28 23:10:23 volumio volumio[931]: info: Loading plugin "volumiodiscovery"... Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 28 23:10:23 volumio node[931]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 23:10:23 volumio node[931]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** For more information see Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 23:10:23 volumio volumio[931]: *** WARNING *** For more information see Nov 28 23:10:23 volumio node[931]: *** WARNING *** For more information see Nov 28 23:10:23 volumio node[931]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 28 23:10:23 volumio node[931]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 28 23:10:23 volumio node[931]: *** WARNING *** For more information see Nov 28 23:10:23 volumio volumio[931]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 28 23:10:23 volumio volumio[931]: info: Discovery: Started advertising with name: Volumio Nov 28 23:10:23 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 28 23:10:23 volumio volumio[931]: info: Loading plugin "spop"... Nov 28 23:10:23 volumio sudo[1061]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:23 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Nov 28 23:10:23 volumio systemd[1]: Started Daily apt upgrade and clean activities. Nov 28 23:10:23 volumio systemd[1]: Startup finished in 15.792s (kernel) + 49.193s (userspace) = 1min 4.985s. Nov 28 23:10:26 volumio volumio[931]: info: Loading plugin "outputs"... Nov 28 23:10:26 volumio volumio[931]: info: Loading plugin "albumart"... Nov 28 23:10:26 volumio volumio[931]: info: Plugin example_plugin is not enabled Nov 28 23:10:26 volumio volumio[931]: info: Loading plugin "inputs"... Nov 28 23:10:26 volumio volumio[931]: info: Loading plugin "updater_comm"... Nov 28 23:10:26 volumio volumio[931]: info: Plugin mpdemulation is not enabled Nov 28 23:10:26 volumio volumio[931]: info: Loading plugin "rest_api"... Nov 28 23:10:27 volumio volumio[931]: info: Loading plugin "websocket"... Nov 28 23:10:27 volumio volumio[931]: info: Starting Socket.io Server version 2.3.0 Nov 28 23:10:27 volumio volumio[931]: info: Loading plugin "touch_display"... Nov 28 23:10:27 volumio volumio[931]: Forking 3 albumart workers Nov 28 23:10:27 volumio volumio[931]: info: Applying required configuration parameters for plugin touch_display Nov 28 23:10:28 volumio volumio[931]: info: Loading i18n strings for locale en Nov 28 23:10:28 volumio volumio[931]: Updating browse sources language Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::initPlayerControls Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:28 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 23:10:29 volumio volumio[931]: Express server listening on port 3000 Nov 28 23:10:29 volumio volumio[931]: [Metrics] WebUI: 20s 769.78ms Nov 28 23:10:29 volumio volumio[931]: info: CoreStateMachine::resetVolumioState Nov 28 23:10:29 volumio volumio[931]: info: CoreStateMachine::getcurrentVolume Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::volumioRetrievevolume Nov 28 23:10:29 volumio volumio[931]: info: Cannot read play queue from file Nov 28 23:10:29 volumio volumio[931]: info: Volumio Network Manager: Network status updated: 2 Nov 28 23:10:29 volumio volumio[931]: Starting albumart workers Nov 28 23:10:29 volumio volumio[931]: Starting albumart workers Nov 28 23:10:29 volumio volumio[931]: Starting albumart workers Nov 28 23:10:29 volumio volumio[931]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Nov 28 23:10:29 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 28 23:10:29 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:29 volumio volumio[931]: info: VolumeController:: Volume=undefined Mute =false Nov 28 23:10:29 volumio volumio[931]: info: CoreStateMachine::pushState Nov 28 23:10:29 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::updateTrackBlock Nov 28 23:10:30 volumio volumio[931]: info: CorePlayQueue::getTrackBlock Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioRetrievevolume Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::setRepeat null single undefined Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::pushState Nov 28 23:10:30 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::setRandom null Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::pushState Nov 28 23:10:30 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Nov 28 23:10:30 volumio volumio[931]: info: Setting Device type: Raspberry PI Nov 28 23:10:30 volumio volumio[931]: info: Completed loading Core Plugins Nov 28 23:10:30 volumio volumio[931]: info: Preparing to generate the ALSA configuration file Nov 28 23:10:30 volumio volumio[931]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Nov 28 23:10:30 volumio sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 28 23:10:30 volumio sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:30 volumio sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 28 23:10:30 volumio sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:30 volumio sudo[1201]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:30 volumio volumio[931]: info: Discovery: adding a60b0253-119e-446d-b73e-aa94fff40e6e Nov 28 23:10:30 volumio volumio[931]: info: Discovery: Found device Volumio Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:30 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:30 volumio sudo[1199]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:30 volumio volumio[931]: info: VolumeController:: Volume=undefined Mute =false Nov 28 23:10:30 volumio volumio[931]: info: CoreStateMachine::pushState Nov 28 23:10:30 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Nov 28 23:10:30 volumio volumio[931]: info: Asound.conf file unchanged, so no further update is needed Nov 28 23:10:30 volumio volumio[931]: info: Output device has changed, restarting MPD Nov 28 23:10:30 volumio sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 28 23:10:30 volumio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:30 volumio volumio[931]: info: Output device has changed, restarting Shairport Sync Nov 28 23:10:30 volumio sudo[1208]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:30 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:30 volumio sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 28 23:10:30 volumio sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:30 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 23:10:30 volumio volumio[931]: info: ___________ START PLUGINS ___________ Nov 28 23:10:30 volumio volumio[931]: info: ControllerMpd::onStart: Initializing MPD Nov 28 23:10:30 volumio systemd[1]: Stopping Music Player Daemon... Nov 28 23:10:30 volumio volumio[931]: info: Creating MPD Configuration file Nov 28 23:10:31 volumio sudo[1230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 28 23:10:31 volumio sudo[1230]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:31 volumio sudo[1230]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 23:10:31 volumio volumio[931]: info: [1732828231070] CoreMusicLibrary::Adding element Media Servers Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:31 volumio sudo[1236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 28 23:10:31 volumio sudo[1236]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:31 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:31 volumio volumio-remote-updater[543]: [2024-11-28 23:10:31] [connect] Successful connection Nov 28 23:10:31 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 23:10:31 volumio volumio[931]: info: [1732828231364] CoreMusicLibrary::Adding element Last_100 Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 23:10:31 volumio volumio[931]: info: [1732828231371] CoreMusicLibrary::Adding element Webradio Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 23:10:31 volumio volumio[931]: info: Initializing BBC Radios Nov 28 23:10:31 volumio volumio[931]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:31 volumio systemd[1]: mpd.service: Succeeded. Nov 28 23:10:31 volumio systemd[1]: Stopped Music Player Daemon. Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:31 volumio systemd[1]: Starting Music Player Daemon... Nov 28 23:10:31 volumio volumio[931]: info: Creating Spotify config file Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:31 volumio volumio[931]: info: Loading i18n strings for locale en Nov 28 23:10:31 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 23:10:31 volumio sudo[1258]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 28 23:10:31 volumio sudo[1258]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:31 volumio volumio[931]: info: Volumio Calling Home Nov 28 23:10:31 volumio sudo[1258]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:32 volumio sudo[1272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Nov 28 23:10:32 volumio sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Nov 28 23:10:32 volumio sudo[1272]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio sudo[1274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 28 23:10:32 volumio sudo[1274]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio systemd[1]: Reloading. Nov 28 23:10:32 volumio sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 28 23:10:32 volumio sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio sudo[1280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 28 23:10:32 volumio sudo[1280]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio sudo[1282]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:32 volumio volumio[931]: info: touch_display: Backlight interface detected. Nov 28 23:10:32 volumio volumio[931]: info: MPD Permissions set Nov 28 23:10:32 volumio volumio[931]: info: MPD Permissions set Nov 28 23:10:32 volumio sudo[1280]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:32 volumio volumio-remote-updater[543]: [2024-11-28 23:10:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1732828231 101 Nov 28 23:10:32 volumio volumio[931]: 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 Nov 28 23:10:32 volumio volumio[931]: info: Spotify config file written Nov 28 23:10:32 volumio sudo[1288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 28 23:10:32 volumio sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio sudo[1291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 28 23:10:32 volumio sudo[1291]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:32 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Nov 28 23:10:32 volumio volumio[931]: info: Volumio called home Nov 28 23:10:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 28 23:10:33 volumio volumio[931]: info: No need to fix Spotify hosts Nov 28 23:10:33 volumio volumio[931]: info: touch_display: Raspberry Pi Foundation touch screen detected. Nov 28 23:10:33 volumio sudo[1317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Nov 28 23:10:33 volumio sudo[1317]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:33 volumio volumio[931]: verbose: New Socket.io Connection to 10.20.10.110 from 10.20.10.10 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Nov 28 23:10:33 volumio sudo[1317]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:34 volumio sudo[1320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Nov 28 23:10:34 volumio sudo[1320]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:34 volumio sudo[1320]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:34 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 28 23:10:34 volumio volumio[931]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Nov 28 23:10:34 volumio volumio[931]: info: Starting Shairport Sync Nov 28 23:10:34 volumio volumio[931]: info: Starting Shairport Sync Nov 28 23:10:34 volumio volumio[931]: info: Starting Shairport Sync Nov 28 23:10:34 volumio sudo[1323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 28 23:10:34 volumio sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:34 volumio sudo[1325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 28 23:10:34 volumio sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio sudo[1328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 28 23:10:34 volumio sudo[1328]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:34 volumio volumio[931]: info: touch_display: File permissions for backlight brightness control set. Nov 28 23:10:34 volumio volumio[931]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 28 23:10:34 volumio volumio[931]: SPOTIFY: BQDQZ5UAmOl8jB-Auv7nkkOMIdV-XFh6EieW6yNGZ1OhFx_wW42A3wYRHNQtM5wAmfFkkG8VETDAyIkrfepT9UL1vA74FpQUAnyHglyIcs5_W0j5Q-TmraxqVOhhFkDK7d_Q6jHb1sJM9lEgCYMYFNFwI-JXFExgbb-2flfmUuV4wMRxI2blhUwR9bv515UHsUHlPEOlWpr9y-3T2XccQzTOwMDYQ2HV6Y0czpBz7R312PIgJDi4C6YdXXzDw4env4L6k-RSlEjZHk1N8P0 Nov 28 23:10:34 volumio volumio[931]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 28 23:10:34 volumio volumio[931]: info: New Spotify access token = BQDQZ5UAmOl8jB-Auv7nkkOMIdV-XFh6EieW6yNGZ1OhFx_wW42A3wYRHNQtM5wAmfFkkG8VETDAyIkrfepT9UL1vA74FpQUAnyHglyIcs5_W0j5Q-TmraxqVOhhFkDK7d_Q6jHb1sJM9lEgCYMYFNFwI-JXFExgbb-2flfmUuV4wMRxI2blhUwR9bv515UHsUHlPEOlWpr9y-3T2XccQzTOwMDYQ2HV6Y0czpBz7R312PIgJDi4C6YdXXzDw4env4L6k-RSlEjZHk1N8P0 Nov 28 23:10:34 volumio volumio[931]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 28 23:10:34 volumio volumio[931]: verbose: New Socket.io Connection to 10.20.10.110 from 10.20.10.10 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetVisibleSources Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 28 23:10:34 volumio volumio[931]: info: Received Get System Info Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 28 23:10:34 volumio volumio[931]: info: Discovery: Getting this device information Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: Listing playlists Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 28 23:10:34 volumio volumio[931]: info: Received Get System Info Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 28 23:10:34 volumio volumio[931]: info: Discovery: Getting this device information Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetVisibleSources Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 28 23:10:34 volumio volumio[931]: info: Received Get System Info Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 28 23:10:34 volumio volumio[931]: info: Discovery: Getting this device information Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 28 23:10:34 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:34 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:34 volumio volumio[931]: info: Listing playlists Nov 28 23:10:34 volumio volumio[931]: SPOTIFY: User informations: {"country":"EG","display_name":"معتز سالم","email":"moutazsalem@yahoo.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31nohowztxgyhq6i6ub2cqsjj6fu"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/31nohowztxgyhq6i6ub2cqsjj6fu","id":"31nohowztxgyhq6i6ub2cqsjj6fu","images":[{"height":300,"url":"https://scontent-bru2-1.xx.fbcdn.net/v/t1.6435-1/55611113_10157116316767154_2283196939447042048_n.jpg?stp=dst-jpg_s240x240_tt6&_nc_cat=100&ccb=1-7&_nc_sid=3e9727&_nc_ohc=sKBUWk5Zt6oQ7kNvgHt9ZNR&_nc_zt=24&_nc_ht=scontent-bru2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=AfCCH93za1jDYq3ve_FuQMA&oh=00_AYDAM-c5oV0yBIuSgH8VBjlMfZ0opm6zJl7Vu5TDNirsMw&oe=676FB92A","width":300},{"height":64,"url":"https://scontent-bru2-1.xx.fbcdn.net/v/t1.6435-1/55611113_10157116316767154_2283196939447042048_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=100&ccb=1-7&_nc_sid=6738e8&_nc_ohc=sKBUWk5Zt6oQ7kNvgHt9ZNR&_nc_zt=24&_nc_ht=scontent-bru2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=AfCCH93za1jDYq3ve_FuQMA&oh=00_AYAjaW5rX2clKRy-9JNr7aSb5IpPWDig_ESfLFgS_swFgQ&oe=676FB92A","width":64}],"product":"premium","type":"user","uri":"spotify:user:31nohowztxgyhq6i6ub2cqsjj6fu"} Nov 28 23:10:34 volumio volumio[931]: info: Spotify Successfully logged in Nov 28 23:10:35 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 28 23:10:35 volumio volumio[931]: info: [1732828235003] CoreMusicLibrary::Adding element Spotify Nov 28 23:10:35 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 28 23:10:35 volumio volumio[931]: Cannot find translation for source Spotify Nov 28 23:10:35 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Nov 28 23:10:35 volumio systemd[1]: mpd.service: Failed with result 'protocol'. Nov 28 23:10:35 volumio systemd[1]: Failed to start Music Player Daemon. Nov 28 23:10:35 volumio sudo[1274]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:35 volumio sudo[1211]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:35 volumio sudo[1236]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:35 volumio volumio[931]: info: touch_display: systemctl daemon-reload succeeded. Nov 28 23:10:35 volumio systemd[1]: Reloading. Nov 28 23:10:35 volumio volumio[931]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Nov 28 23:10:35 volumio volumio[931]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Nov 28 23:10:35 volumio volumio[931]: See "systemctl status mpd.service" and "journalctl -xe" for details. Nov 28 23:10:35 volumio volumio[931]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Nov 28 23:10:35 volumio volumio[931]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Nov 28 23:10:35 volumio volumio[931]: See "systemctl status mpd.service" and "journalctl -xe" for details. Nov 28 23:10:35 volumio sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Nov 28 23:10:35 volumio sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:35 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Nov 28 23:10:35 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 28 23:10:36 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 28 23:10:36 volumio sudo[1272]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:36 volumio volumio[931]: info: touch_display: systemctl disable getty@tty1.service succeeded. Nov 28 23:10:37 volumio systemd[1]: Started Volumio Kiosk. Nov 28 23:10:37 volumio sudo[1334]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 28 23:10:37 volumio volumio[931]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Nov 28 23:10:37 volumio volumio[931]: info: touch_display: Volumio Kiosk started. Nov 28 23:10:37 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Nov 28 23:10:37 volumio sudo[1291]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:37 volumio systemd[1]: Started go-librespot Daemon. Nov 28 23:10:37 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:37 volumio sudo[1288]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio go-librespot[1356]: Librespot-go daemon starting... Nov 28 23:10:37 volumio volumio[931]: info: Completed starting Core Plugins Nov 28 23:10:37 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:37 volumio volumio[931]: info: ----- MyVolumio plugins startup ---- Nov 28 23:10:37 volumio volumio[931]: info: ------------------------------------------- Nov 28 23:10:37 volumio volumio[931]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 28 23:10:37 volumio systemd[1]: Starting Music Player Daemon... Nov 28 23:10:37 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:10:37 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:10:37 volumio volumio[931]: info: Upmpdcli Daemon Started Nov 28 23:10:37 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 28 23:10:37 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 28 23:10:37 volumio sudo[1359]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 28 23:10:37 volumio sudo[1359]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:10:37 volumio sudo[1270]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio sudo[1359]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio volumio[931]: info: touch_display: systemctl stop getty@tty1.service succeeded. Nov 28 23:10:37 volumio volumio[931]: info: touch_display: X display number found: 0 Nov 28 23:10:37 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 28 23:10:37 volumio sudo[1323]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio sudo[1325]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio sudo[1328]: pam_unix(sudo:session): session closed for user root Nov 28 23:10:37 volumio volumio[931]: info: Shairport-Sync Started Nov 28 23:10:37 volumio volumio[931]: Error adding Membership: Error: addMembership EINVAL Nov 28 23:10:37 volumio volumio[931]: info: Shairport-Sync Started Nov 28 23:10:37 volumio volumio[931]: info: touch_display: X display number found: 0 Nov 28 23:10:37 volumio volumio[931]: info: touch_display: X display number found: 0 Nov 28 23:10:37 volumio volumio[931]: info: Shairport-Sync Started Nov 28 23:10:37 volumio volumio[931]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Nov 28 23:10:37 volumio startx[1350]: X.Org X Server 1.20.4 Nov 28 23:10:37 volumio startx[1350]: X Protocol Version 11, Revision 0 Nov 28 23:10:37 volumio startx[1350]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Nov 28 23:10:37 volumio startx[1350]: Current Operating System: Linux volumio 6.6.56-v7+ #1803 SMP Thu Oct 10 14:08:55 BST 2024 armv7l Nov 28 23:10:37 volumio startx[1350]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=ed280c2b-b4b4-43e6-87d7-b67377eacab2 imgfile=/volumio_current.sqsh bootpart=UUID=FCA2-3F9A datapart=UUID=0367e456-8c2f-458a-8465-47f124ad9fdd uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Nov 28 23:10:37 volumio startx[1350]: Build Date: 04 April 2023 07:50:56AM Nov 28 23:10:37 volumio startx[1350]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Nov 28 23:10:37 volumio startx[1350]: Current version of pixman: 0.36.0 Nov 28 23:10:37 volumio startx[1350]: Before reporting problems, check http://wiki.x.org Nov 28 23:10:37 volumio startx[1350]: to make sure that you have the latest version. Nov 28 23:10:37 volumio startx[1350]: Markers: (--) probed, (**) from config file, (==) default setting, Nov 28 23:10:37 volumio startx[1350]: (++) from command line, (!!) notice, (II) informational, Nov 28 23:10:37 volumio startx[1350]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Nov 28 23:10:37 volumio startx[1350]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Nov 28 23:10:37 2024 Nov 28 23:10:37 volumio go-librespot[1356]: time="2024-11-28T23:10:37+02:00" level=info msg="generated new device id: 55cb50f34fee736d775aecd8e32679698d875da4" Nov 28 23:10:37 volumio go-librespot[1356]: time="2024-11-28T23:10:37+02:00" level=debug msg="stored credentials found for 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:10:37 volumio startx[1350]: (==) Using config directory: "/etc/X11/xorg.conf.d" Nov 28 23:10:37 volumio startx[1350]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Nov 28 23:10:37 volumio volumio[931]: info: touch_display: X display number found: 0 Nov 28 23:10:37 volumio volumio[931]: info: touch_display: X display number found: 0 Nov 28 23:10:38 volumio go-librespot[1356]: time="2024-11-28T23:10:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 28 23:10:38 volumio go-librespot[1356]: time="2024-11-28T23:10:38+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 28 23:10:38 volumio go-librespot[1356]: time="2024-11-28T23:10:38+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 28 23:10:38 volumio go-librespot[1356]: time="2024-11-28T23:10:38+02:00" level=debug msg="zeroconf server listening on port 40129" Nov 28 23:10:39 volumio go-librespot[1356]: time="2024-11-28T23:10:39+02:00" level=debug msg="obtained new client token: AACMBFH06gW8iWdbvYtrCzclSoKIMcGNBpu4CrFI4uyH9WB+5pKBLBkSP/A0iH/nFAfRDhea+kwroc9lPtcZ0Q1Lo2eaU9VlzqigC+D5k+0aALNtwMct7t7oGbROZDn9Icfr6UPL/8nJ9D1T7MUJ4lG31DzQSd3JRuwcyXWhwNE4OheCvdON5fP19QoEaXjymIg+dC6xzUlIfq94lT0394hUBYp9xOCStFZ8PGHyL97fs47Q3KP0dr0aaQ==" Nov 28 23:10:39 volumio go-librespot[1356]: time="2024-11-28T23:10:39+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Nov 28 23:10:39 volumio go-librespot[1356]: time="2024-11-28T23:10:39+02:00" level=debug msg="completed keyexchange" Nov 28 23:10:39 volumio go-librespot[1356]: time="2024-11-28T23:10:39+02:00" level=debug msg="completed challenge" Nov 28 23:10:39 volumio go-librespot[1356]: time="2024-11-28T23:10:39+02:00" level=debug msg="authenticated as 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:10:40 volumio systemd[1]: systemd-timedated.service: Succeeded. Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="authenticated as 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:10:40 volumio volumio[931]: info: go-librespot daemon successfully initialized Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="dealer connection opened" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="initializing zeroconf session, username: 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="received connection id: YjI0N2M1YjktZDlmNy00NTQ3LTg5OGQtODQ3NDk1MGNlOTYzK2RlYWxlcit0Y3A6Ly8wYWNhNDBmZS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMDJFRDc5RTYxOTBEODBDMjQ2MEY2QTg1NTAzMDdBQUQ4MzE5MTNBN0E4QURCOEIzODcyRjBGNkY1OUQ0RTU2MQ==" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="put connect state because NEW_DEVICE" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 28 23:10:40 volumio go-librespot[1356]: time="2024-11-28T23:10:40+02:00" level=debug msg="autoplay enabled: false" Nov 28 23:10:41 volumio volumio[931]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 28 23:10:42 volumio mpd[1389]: Nov 28 23:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 28 23:10:42 volumio systemd[1]: Started Music Player Daemon. Nov 28 23:10:42 volumio volumio[931]: Upnp client error: Error: This socket has been ended by the other party Nov 28 23:10:42 volumio mpd_monitor.sh[566]: MPD restarted due to no mpc output. Nov 28 23:10:42 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Nov 28 23:10:42 volumio volumio[931]: assert.ok(self.idling) Nov 28 23:10:42 volumio volumio[931]: error: The expression evaluated to a falsy value: Nov 28 23:10:42 volumio volumio[931]: assert.ok(self.idling) Nov 28 23:10:42 volumio volumio[931]: error: updateQueue error: null Nov 28 23:10:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 28 23:10:43 volumio volumio[1352]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 28 23:10:43 volumio volumio[931]: info: Initializing connection to go-librespot Websocket Nov 28 23:10:43 volumio go-librespot[1356]: time="2024-11-28T23:10:43+02:00" level=debug msg="new websocket client" Nov 28 23:10:43 volumio volumio[931]: info: Connection to go-librespot Websocket established Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 28 23:10:45 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin bluetooth to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin multiroom to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin metavolumio to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin cd_controller to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 28 23:10:46 volumio volumio[931]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="handling transfer player command from 72080b76f79fb9e6073cb87da435b2a743f16990" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="resolved context of track" uri="spotify:artist:2N72bJ8IYB4KZmKmxz5Xkk" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=trace msg="fetched new page 0 with 5 items (list: 5)" uri="spotify:artist:2N72bJ8IYB4KZmKmxz5Xkk" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="loading track (paused: false, position: 587300ms)" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1863" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=trace msg="emitting websocket event: will_play" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="selected format OGG_VORBIS_320 (b39fffe75bab8b2189c729903bb423d476b66092)" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:49 volumio go-librespot[1356]: time="2024-11-28T23:10:49+02:00" level=debug msg="requested aes key for file b39fffe75bab8b2189c729903bb423d476b66092, gid: 03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:50 volumio go-librespot[1356]: time="2024-11-28T23:10:50+02:00" level=debug msg="fetched first chunk of 21, total size is 10878368 bytes" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:50 volumio go-librespot[1356]: time="2024-11-28T23:10:50+02:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:51 volumio ntpd[733]: Soliciting pool server 196.200.160.123 Nov 28 23:10:51 volumio ntpd[733]: Soliciting pool server 102.64.113.152 Nov 28 23:10:51 volumio go-librespot[1356]: time="2024-11-28T23:10:51+02:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:51 volumio go-librespot[1356]: time="2024-11-28T23:10:51+02:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:51 volumio go-librespot[1356]: time="2024-11-28T23:10:51+02:00" level=debug msg="fetched chunk 20/20, size: 392608" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:51 volumio go-librespot[1356]: time="2024-11-28T23:10:51+02:00" level=trace msg="seek to 270237ms (diff: 2823ms, samples: 11917451, bytes: 10850176)" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:51 volumio ntpd[733]: Soliciting pool server 196.44.136.165 Nov 28 23:10:51 volumio ntpd[733]: Soliciting pool server 196.10.55.57 Nov 28 23:10:51 volumio ntpd[733]: Soliciting pool server 196.10.54.57 Nov 28 23:10:52 volumio go-librespot[1356]: time="2024-11-28T23:10:52+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" Nov 28 23:10:52 volumio go-librespot[1356]: time="2024-11-28T23:10:52+02:00" level=debug msg="created new output device" Nov 28 23:10:52 volumio go-librespot[1356]: time="2024-11-28T23:10:52+02:00" level=info msg="loaded track \"Dari Ya Alby\" (paused: false, position: 587300ms, duration: 270237ms, prefetched: false)" uri="spotify:track:03OoXcz5TPOCyU6RTR1bgk" Nov 28 23:10:52 volumio ntpd[733]: Soliciting pool server 196.10.54.58 Nov 28 23:10:52 volumio ntpd[733]: Soliciting pool server 197.224.66.40 Nov 28 23:10:52 volumio ntpd[733]: Soliciting pool server 196.10.52.57 Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="prefetching next track" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="emitting websocket event: metadata" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="emitting websocket event: active" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="sending successful reply for dealer request" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="selected format OGG_VORBIS_320 (067ce78b250a7a6de1c9d793b60adccc7fab8007)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="requested aes key for file 067ce78b250a7a6de1c9d793b60adccc7fab8007, gid: 3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="emitting websocket event: playing" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="emitting websocket event: not_playing" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="fetched first chunk of 20, total size is 10150592 bytes" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="emitting websocket event: will_play" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:10:53 volumio go-librespot[1356]: time="2024-11-28T23:10:53+02:00" level=trace msg="cleared closed output device" Nov 28 23:10:53 volumio go-librespot[1356]: panic: runtime error: invalid memory address or nil pointer dereference Nov 28 23:10:53 volumio go-librespot[1356]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x57277c] Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 92 gp=0x2c84d88 m=5 mp=0x2c80008 [running]: Nov 28 23:10:53 volumio go-librespot[1356]: panic({0x5eab20, 0xa60098}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:779 +0x12c fp=0x3017de8 sp=0x3017d94 pc=0x58364 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.panicmem(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:261 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.sigpanic() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/signal_unix.go:881 +0x39c fp=0x3017e18 sp=0x3017de8 pc=0x74350 Nov 28 23:10:53 volumio go-librespot[1356]: main.(*AppPlayer).prefetchNext(0x2c27d60) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:42 +0x4c4 fp=0x3017fe4 sp=0x3017e1c pc=0x57277c Nov 28 23:10:53 volumio go-librespot[1356]: main.(*AppPlayer).schedulePrefetchNext.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:56 +0x28 fp=0x3017fec sp=0x3017fe4 pc=0x572d68 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x3017fec sp=0x3017fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by main.(*AppPlayer).schedulePrefetchNext in goroutine 86 Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:56 +0x1c8 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 1 gp=0x2c02128 m=nil [select]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c53d0c sp=0x2c53cf8 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.selectgo(0x2c53e0c, 0x2e13dd8, 0x0, 0x0, 0x2, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2c53dac sp=0x2c53d0c pc=0x705e4 Nov 28 23:10:53 volumio go-librespot[1356]: go-librespot/zeroconf.(*Zeroconf).Serve(0x2c27c20, 0x2c53e88) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:268 +0x228 fp=0x2c53e50 sp=0x2c53dac pc=0x528c80 Nov 28 23:10:53 volumio go-librespot[1356]: main.(*App).withAppPlayer(0x2c92150, 0x2d02880) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:297 +0x4b0 fp=0x2c53ec0 sp=0x2c53e50 pc=0x578aac Nov 28 23:10:53 volumio go-librespot[1356]: main.(*App).withCredentials(0x2c92150, {0x5f3170, 0x2c900e0}) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:171 +0x3d4 fp=0x2c53f1c sp=0x2c53ec0 pc=0x578184 Nov 28 23:10:53 volumio go-librespot[1356]: main.(*App).SpotifyToken(...) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:131 Nov 28 23:10:53 volumio go-librespot[1356]: main.main() Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:466 +0x530 fp=0x2c53fa8 sp=0x2c53f1c pc=0x57a0cc Nov 28 23:10:53 volumio go-librespot[1356]: runtime.main() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:271 +0x2fc fp=0x2c53fec sp=0x2c53fa8 pc=0x5c29c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c53fec sp=0x2c53fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 18 gp=0x2c84248 m=nil [force gc (idle)]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0xaa84c0, 0x11, 0xa, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c3e7d4 sp=0x2c3e7c0 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.forcegchelper() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:326 +0xe4 fp=0x2c3e7ec sp=0x2c3e7d4 pc=0x5c668 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c3e7ec sp=0x2c3e7ec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.init.5 in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:314 +0x1c Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 2 gp=0x2c02c68 m=nil [runnable]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goschedIfBusy() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:365 +0x34 fp=0x2c42fc4 sp=0x2c42fb8 pc=0x5c714 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.bgsweep(0x2c72000) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcsweep.go:302 +0x188 fp=0x2c42fe4 sp=0x2c42fc4 pc=0x450d8 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcenable.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x28 fp=0x2c42fec sp=0x2c42fe4 pc=0x3518c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c42fec sp=0x2c42fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcenable in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x74 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 3 gp=0x2c02d88 m=nil [GC scavenge wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0xaa9020, 0xd, 0xa, 0x2) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c437b4 sp=0x2c437a0 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.(*scavengerState).park(0xaa9020) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:425 +0x68 fp=0x2c437c8 sp=0x2c437b4 pc=0x4238c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.bgscavenge(0x2c72000) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:658 +0x60 fp=0x2c437e4 sp=0x2c437c8 pc=0x42ac4 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcenable.gowrap2() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0x28 fp=0x2c437ec sp=0x2c437e4 pc=0x35138 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c437ec sp=0x2c437ec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcenable in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0xbc Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 4 gp=0x2c030e8 m=nil [finalizer wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f7e4, 0xad3bac, 0x10, 0xa, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c43f8c sp=0x2c43f78 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.runfinq() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:194 +0x110 fp=0x2c43fec sp=0x2c43f8c pc=0x33f78 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c43fec sp=0x2c43fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.createfing in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:164 +0x5c Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 19 gp=0x2c845a8 m=nil [IO wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609eed8, 0x2, 0x2, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c3eddc sp=0x2c3edc8 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.netpollblock(0x7609eec8, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2c3edf4 sp=0x2c3eddc pc=0x540f0 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609eec8, 0x72) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2c3ee08 sp=0x2c3edf4 pc=0x8eba8 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2ccace8, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2c3ee1c sp=0x2c3ee08 pc=0x108108 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*FD).Accept(0x2ccacd0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x2c3ee64 sp=0x2c3ee1c pc=0x10c974 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*netFD).accept(0x2ccacd0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x2c3eecc sp=0x2c3ee64 pc=0x2a2504 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*TCPListener).accept(0x2ccc150) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x2c3eee4 sp=0x2c3eecc pc=0x2ba604 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*TCPListener).Accept(0x2ccc150) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x2c3ef00 sp=0x2c3eee4 pc=0x2b9670 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*onceCloseListener).Accept(0x2c75160) Nov 28 23:10:53 volumio go-librespot[1356]: :1 +0x34 fp=0x2c3ef18 sp=0x2c3ef00 pc=0x45e914 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*Server).Serve(0x2d84aa8, {0x72527c, 0x2ccc150}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x2c3efb0 sp=0x2c3ef18 pc=0x43cfd0 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.Serve(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Nov 28 23:10:53 volumio go-librespot[1356]: main.(*ApiServer).serve(0x2cc6600) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:470 +0x5ec fp=0x2c3efe4 sp=0x2c3efb0 pc=0x57084c Nov 28 23:10:53 volumio go-librespot[1356]: main.NewApiServer.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x28 fp=0x2c3efec sp=0x2c3efe4 pc=0x56ff20 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c3efec sp=0x2c3efec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by main.NewApiServer in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x224 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 69 gp=0x2d40248 m=nil [IO wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ea78, 0x2, 0x2, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x3016ad4 sp=0x3016ac0 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.netpollblock(0x7609ea68, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x3016aec sp=0x3016ad4 pc=0x540f0 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609ea68, 0x72) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x3016b00 sp=0x3016aec pc=0x8eba8 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2ebcf68, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x3016b14 sp=0x3016b00 pc=0x108108 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2ebcf50, {0x2e69000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x3016b5c sp=0x3016b14 pc=0x1092f4 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*netFD).Read(0x2ebcf50, {0x2e69000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x3016b88 sp=0x3016b5c pc=0x2a0610 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*conn).Read(0x2d01cb0, {0x2e69000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x3016bb4 sp=0x3016b88 pc=0x2b07f0 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2d01cb0, {0x2e69000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: :1 +0x44 fp=0x3016bd4 sp=0x3016bb4 pc=0x2c3a44 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2fc87c0, {0x2e69000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x3016c00 sp=0x3016bd4 pc=0x386018 Nov 28 23:10:53 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x2dc8ccc, {0x723a98, 0x2fc87c0}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x3016c3c sp=0x3016c00 pc=0x136d6c Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x2dc8b48, {0x722604, 0x2d01cb0}, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x3016c64 sp=0x3016c3c pc=0x386274 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2dc8b48, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x3016dc8 sp=0x3016c64 pc=0x383974 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2dc8b48, {0x3081000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x3016df8 sp=0x3016dc8 pc=0x3897e4 Nov 28 23:10:53 volumio go-librespot[1356]: bufio.(*Reader).Read(0x2fcade0, {0x2d184a4, 0x9, 0x9}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x3016e1c sp=0x3016df8 pc=0x15ab44 Nov 28 23:10:53 volumio go-librespot[1356]: io.ReadAtLeast({0x7227f8, 0x2fcade0}, {0x2d184a4, 0x9, 0x9}, 0x9) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x3016e48 sp=0x3016e1c pc=0x1020b0 Nov 28 23:10:53 volumio go-librespot[1356]: io.ReadFull(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.http2readFrameHeader({0x2d184a4, 0x9, 0x9}, {0x7227f8, 0x2fcade0}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x3016e70 sp=0x3016e48 pc=0x3f30fc Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2Framer).ReadFrame(0x2d18480) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x3016eec sp=0x3016e70 pc=0x3f3894 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2clientConnReadLoop).run(0x3016fdc) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x3016fa4 sp=0x3016eec pc=0x4180b0 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2ClientConn).readLoop(0x2d16308) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x3016fe4 sp=0x3016fa4 pc=0x4175a4 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2Transport).newClientConn.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x3016fec sp=0x3016fe4 pc=0x4105f0 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x3016fec sp=0x3016fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by net/http.(*http2Transport).newClientConn in goroutine 68 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 6 gp=0x2d40488 m=nil [GC worker (idle)]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f7f4, 0x2caa0c0, 0x1a, 0xa, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5e790 sp=0x2d5e77c pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcBgMarkWorker() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x2d5e7ec sp=0x2d5e790 pc=0x37db4 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5e7ec sp=0x2d5e7ec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcBgMarkStartWorkers in goroutine 5 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 50 gp=0x304c008 m=nil [GC worker (idle)]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f7f4, 0x2fc02d0, 0x1a, 0xa, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5a790 sp=0x2d5a77c pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcBgMarkWorker() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x2d5a7ec sp=0x2d5a790 pc=0x37db4 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5a7ec sp=0x2d5a7ec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcBgMarkStartWorkers in goroutine 5 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 7 gp=0x2c037a8 m=nil [GC worker (idle)]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f7f4, 0x2fc02e8, 0x1a, 0xa, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c42790 sp=0x2c4277c pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcBgMarkWorker() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x2c427ec sp=0x2c42790 pc=0x37db4 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c427ec sp=0x2c427ec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcBgMarkStartWorkers in goroutine 5 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 39 gp=0x2d40908 m=nil [GC worker (idle)]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f7f4, 0x2fc0300, 0x1a, 0xa, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5ef90 sp=0x2d5ef7c pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gcBgMarkWorker() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xec fp=0x2d5efec sp=0x2d5ef90 pc=0x37db4 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5efec sp=0x2d5efec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by runtime.gcBgMarkStartWorkers in goroutine 5 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x20 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 9 gp=0x2d405a8 m=nil [IO wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ee38, 0x2, 0x2, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e46ad4 sp=0x2e46ac0 pc=0x5c82c Nov 28 23:10:53 volumio ntpd[733]: Soliciting pool server 196.10.52.58 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.netpollblock(0x7609ee28, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e46aec sp=0x2e46ad4 pc=0x540f0 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609ee28, 0x72) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e46b00 sp=0x2e46aec pc=0x8eba8 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2d382e8, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e46b14 sp=0x2e46b00 pc=0x108108 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2d382d0, {0x2e24000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2e46b5c sp=0x2e46b14 pc=0x1092f4 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*netFD).Read(0x2d382d0, {0x2e24000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2e46b88 sp=0x2e46b5c pc=0x2a0610 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*conn).Read(0x2c2e330, {0x2e24000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2e46bb4 sp=0x2e46b88 pc=0x2b07f0 Nov 28 23:10:53 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2c2e330, {0x2e24000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: :1 +0x44 fp=0x2e46bd4 sp=0x2e46bb4 pc=0x2c3a44 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2c0ef70, {0x2e24000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x2e46c00 sp=0x2e46bd4 pc=0x386018 Nov 28 23:10:53 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x2dc860c, {0x723a98, 0x2c0ef70}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x2e46c3c sp=0x2e46c00 pc=0x136d6c Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x2dc8488, {0x722604, 0x2c2e330}, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x2e46c64 sp=0x2e46c3c pc=0x386274 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2dc8488, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x2e46dc8 sp=0x2e46c64 pc=0x383974 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:53 volumio ntpd[733]: Soliciting pool server 196.49.100.58 Nov 28 23:10:53 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2dc8488, {0x30d4000, 0x1000, 0x1000}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2e46df8 sp=0x2e46dc8 pc=0x3897e4 Nov 28 23:10:53 volumio go-librespot[1356]: bufio.(*Reader).Read(0x30ccc00, {0x2d180a4, 0x9, 0x9}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x2e46e1c sp=0x2e46df8 pc=0x15ab44 Nov 28 23:10:53 volumio go-librespot[1356]: io.ReadAtLeast({0x7227f8, 0x30ccc00}, {0x2d180a4, 0x9, 0x9}, 0x9) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x2e46e48 sp=0x2e46e1c pc=0x1020b0 Nov 28 23:10:53 volumio go-librespot[1356]: io.ReadFull(...) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.http2readFrameHeader({0x2d180a4, 0x9, 0x9}, {0x7227f8, 0x30ccc00}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x2e46e70 sp=0x2e46e48 pc=0x3f30fc Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2Framer).ReadFrame(0x2d18080) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x2e46eec sp=0x2e46e70 pc=0x3f3894 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2clientConnReadLoop).run(0x2e46fdc) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x2e46fa4 sp=0x2e46eec pc=0x4180b0 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2ClientConn).readLoop(0x2d16108) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x2e46fe4 sp=0x2e46fa4 pc=0x4175a4 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*http2Transport).newClientConn.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x2e46fec sp=0x2e46fe4 pc=0x4105f0 Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e46fec sp=0x2e46fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by net/http.(*http2Transport).newClientConn in goroutine 8 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 101 gp=0x2c846c8 m=nil [select]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c55de4 sp=0x2c55dd0 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.selectgo(0x2c55f78, 0x2c55ebc, 0x0, 0x0, 0x4, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2c55e84 sp=0x2c55de4 pc=0x705e4 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*persistConn).readLoop(0x30c8168) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2261 +0xc68 fp=0x2c55fe4 sp=0x2c55e84 pc=0x4529f0 Nov 28 23:10:53 volumio go-librespot[1356]: net/http.(*Transport).dialConn.gowrap2() Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x28 fp=0x2c55fec sp=0x2c55fe4 pc=0x45083c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c55fec sp=0x2c55fec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by net/http.(*Transport).dialConn in goroutine 27 Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x13f4 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 43 gp=0x2c84c68 m=nil [select]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2fedea8 sp=0x2fede94 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.selectgo(0x2fedfd4, 0x2fedf6c, 0x0, 0x0, 0x2, 0x1) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2fedf48 sp=0x2fedea8 pc=0x705e4 Nov 28 23:10:53 volumio go-librespot[1356]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x2e64288) Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:319 +0x8c fp=0x2fedfe4 sp=0x2fedf48 pc=0x48d514 Nov 28 23:10:53 volumio go-librespot[1356]: go-librespot/ap.NewAccesspoint.gowrap1() Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x28 fp=0x2fedfec sp=0x2fedfe4 pc=0x48b71c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2fedfec sp=0x2fedfec pc=0x9346c Nov 28 23:10:53 volumio go-librespot[1356]: created by go-librespot/ap.NewAccesspoint in goroutine 1 Nov 28 23:10:53 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x188 Nov 28 23:10:53 volumio go-librespot[1356]: goroutine 40 gp=0x304c128 m=nil [IO wait]: Nov 28 23:10:53 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ecf8, 0x2, 0x2, 0x5) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e47e84 sp=0x2e47e70 pc=0x5c82c Nov 28 23:10:53 volumio go-librespot[1356]: runtime.netpollblock(0x7609ece8, 0x72, 0x0) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e47e9c sp=0x2e47e84 pc=0x540f0 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609ece8, 0x72) Nov 28 23:10:53 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e47eb0 sp=0x2e47e9c pc=0x8eba8 Nov 28 23:10:53 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2c27cd8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e47ec4 sp=0x2e47eb0 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).RawRead(0x2c27cc0, 0x2d689f0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x2e47ef0 sp=0x2e47ec4 pc=0x10d578 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*rawConn).Read(0x2d015e8, 0x2d689f0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x2e47f10 sp=0x2e47ef0 pc=0x2b4a2c Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x2e3e390, 0x2d689c0, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x2e47f40 sp=0x2e47f10 pc=0x4c9804 Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x2d69da8, {0x2fb0000, 0x10000, 0x10000}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv4/payload_cmsg.go:32 +0x44c fp=0x2e47f9c sp=0x2e47f40 pc=0x4cd7ec Nov 28 23:10:54 volumio go-librespot[1356]: github.com/grandcat/zeroconf.(*Server).recv4(0x2d0f540, 0x2d69da0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xec fp=0x2e47fe0 sp=0x2e47f9c pc=0x52407c Nov 28 23:10:54 volumio go-librespot[1356]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x2e47fec sp=0x2e47fe0 pc=0x523d34 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e47fec sp=0x2e47fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 52 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 41 gp=0x304c248 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ec58, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5f65c sp=0x2d5f648 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609ec48, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2d5f674 sp=0x2d5f65c pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609ec48, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2d5f688 sp=0x2d5f674 pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2c27d28, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2d5f69c sp=0x2d5f688 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).RawRead(0x2c27d10, 0x2ffe030) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x164 fp=0x2d5f6c8 sp=0x2d5f69c pc=0x10d578 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*rawConn).Read(0x2d01608, 0x2ffe030) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x38 fp=0x2d5f6e8 sp=0x2d5f6c8 pc=0x2b4a2c Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x2e3e3a0, 0x2ffe000, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x154 fp=0x2d5f718 sp=0x2d5f6e8 pc=0x4c9804 Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Nov 28 23:10:54 volumio go-librespot[1356]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x2d69dd8, {0x2fee000, 0x10000, 0x10000}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv6/payload_cmsg.go:32 +0x2ec fp=0x2d5f79c sp=0x2d5f718 pc=0x4d1174 Nov 28 23:10:54 volumio go-librespot[1356]: github.com/grandcat/zeroconf.(*Server).recv6(0x2d0f540, 0x2d69dd0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xec fp=0x2d5f7e0 sp=0x2d5f79c pc=0x524270 Nov 28 23:10:54 volumio go-librespot[1356]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x2d5f7ec sp=0x2d5f7e0 pc=0x523cd8 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5f7ec sp=0x2d5f7ec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 52 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 73 gp=0x2c85568 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609e9d8, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e15938 sp=0x2e15924 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609e9c8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e15950 sp=0x2e15938 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609e9c8, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e15964 sp=0x2e15950 pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2f6a928, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e15978 sp=0x2e15964 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2f6a910, {0x2cda000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2e159c0 sp=0x2e15978 pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2f6a910, {0x2cda000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2e159ec sp=0x2e159c0 pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x2fcc598, {0x2cda000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2e15a18 sp=0x2e159ec pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2fcc598, {0x2cda000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2e15a38 sp=0x2e15a18 pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2e6e190, {0x2cda000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x2e15a64 sp=0x2e15a38 pc=0x386018 Nov 28 23:10:54 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x2d1b80c, {0x723a98, 0x2e6e190}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x2e15aa0 sp=0x2e15a64 pc=0x136d6c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x2d1b688, {0x722604, 0x2fcc598}, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x2e15ac8 sp=0x2e15aa0 pc=0x386274 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2d1b688, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x2e15c2c sp=0x2e15ac8 pc=0x383974 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2d1b688, {0x2f41000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2e15c5c sp=0x2e15c2c pc=0x3897e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*readWriteCloserBody).Read(0x2e3ee90, {0x2f41000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2429 +0xec fp=0x2e15c7c sp=0x2e15c5c pc=0x4538c0 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).fill(0x2e7b980) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x2e15ca0 sp=0x2e15c7c pc=0x15a4b8 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).ReadByte(0x2e7b980) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x28 fp=0x2e15cac sp=0x2e15ca0 pc=0x15ad3c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.readFrameHeader(0x2e7b980, {0x2d48538, 0x8, 0x8}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2e15cec sp=0x2e15cac pc=0x4771e0 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x2d48508, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2e15dac sp=0x2e15cec pc=0x479e44 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).readLoop(0x2d48508, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2e15e70 sp=0x2e15dac pc=0x47992c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).reader(0x2d48508, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x2e15efc sp=0x2e15e70 pc=0x47ab40 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).Reader(...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).Read(0x2d48508, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x2e15f24 sp=0x2e15efc pc=0x479210 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/dealer.(*Dealer).recvLoop(0x2ca9688) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:153 +0x58 fp=0x2e15fe4 sp=0x2e15f24 pc=0x4b8a14 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x28 fp=0x2e15fec sp=0x2e15fe4 pc=0x4ba26c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e15fec sp=0x2e15fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/dealer.(*Dealer).ReceiveMessage.(*Dealer).startReceiving.func1 in goroutine 86 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x60 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 12 gp=0x2c85688 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ebb8, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e42ad4 sp=0x2e42ac0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609eba8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e42aec sp=0x2e42ad4 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609eba8, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e42b00 sp=0x2e42aec pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2f07828, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e42b14 sp=0x2e42b00 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2f07810, {0x30ea000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2e42b5c sp=0x2e42b14 pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2f07810, {0x30ea000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2e42b88 sp=0x2e42b5c pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x30c0c40, {0x30ea000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2e42bb4 sp=0x2e42b88 pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x30c0c40, {0x30ea000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2e42bd4 sp=0x2e42bb4 pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2e3eb30, {0x30ea000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x2e42c00 sp=0x2e42bd4 pc=0x386018 Nov 28 23:10:54 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x2d1accc, {0x723a98, 0x2e3eb30}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x2e42c3c sp=0x2e42c00 pc=0x136d6c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x2d1ab48, {0x722604, 0x30c0c40}, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x2e42c64 sp=0x2e42c3c pc=0x386274 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2d1ab48, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x2e42dc8 sp=0x2e42c64 pc=0x383974 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2d1ab48, {0x30f4000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2e42df8 sp=0x2e42dc8 pc=0x3897e4 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).Read(0x30cde90, {0x2d18124, 0x9, 0x9}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x2e42e1c sp=0x2e42df8 pc=0x15ab44 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadAtLeast({0x7227f8, 0x30cde90}, {0x2d18124, 0x9, 0x9}, 0x9) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x2e42e48 sp=0x2e42e1c pc=0x1020b0 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadFull(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.http2readFrameHeader({0x2d18124, 0x9, 0x9}, {0x7227f8, 0x30cde90}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x2e42e70 sp=0x2e42e48 pc=0x3f30fc Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2Framer).ReadFrame(0x2d18100) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x2e42eec sp=0x2e42e70 pc=0x3f3894 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2clientConnReadLoop).run(0x2e42fdc) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x2e42fa4 sp=0x2e42eec pc=0x4180b0 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2ClientConn).readLoop(0x2d16208) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x2e42fe4 sp=0x2e42fa4 pc=0x4175a4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2Transport).newClientConn.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x2e42fec sp=0x2e42fe4 pc=0x4105f0 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e42fec sp=0x2e42fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*http2Transport).newClientConn in goroutine 11 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 72 gp=0x304c908 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609eb18, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c52d70 sp=0x2c52d5c pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609eb08, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2c52d88 sp=0x2c52d70 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609eb08, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2c52d9c sp=0x2c52d88 pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2f803d8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2c52db0 sp=0x2c52d9c pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2f803c0, {0x2d0cc34, 0x3, 0x3}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2c52df8 sp=0x2c52db0 pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2f803c0, {0x2d0cc34, 0x3, 0x3}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2c52e24 sp=0x2c52df8 pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x2eb8050, {0x2d0cc34, 0x3, 0x3}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2c52e50 sp=0x2c52e24 pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2eb8050, {0x2d0cc34, 0x3, 0x3}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2c52e70 sp=0x2c52e50 pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadAtLeast({0x722604, 0x2eb8050}, {0x2d0cc34, 0x3, 0x3}, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x2c52e9c sp=0x2c52e70 pc=0x1020b0 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadFull(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/ap.(*shannonConn).receivePacket(0x30fb080) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/shannon.go:80 +0x130 fp=0x2c52efc sp=0x2c52e9c pc=0x48fedc Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/ap.(*Accesspoint).recvLoop(0x2e64288) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:251 +0x58 fp=0x2c52fe4 sp=0x2c52efc pc=0x48cda4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x28 fp=0x2c52fec sp=0x2c52fe4 pc=0x48cd20 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c52fec sp=0x2c52fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/ap.(*Accesspoint).Receive.(*Accesspoint).startReceiving.func1 in goroutine 86 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x60 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 83 gp=0x2c859e8 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5be88 sp=0x2d5be74 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2d5bfd4, 0x2d5bf50, 0x0, 0x0, 0x2, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2d5bf28 sp=0x2d5be88 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/dealer.(*Dealer).pingTicker(0x2ca9688) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:107 +0x8c fp=0x2d5bfe4 sp=0x2d5bf28 pc=0x4b85d0 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/dealer.NewDealer.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x2d5bfec sp=0x2d5bfe4 pc=0x4b80a0 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5bfec sp=0x2d5bfec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/dealer.NewDealer in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x180 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 82 gp=0x2c85b08 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2fe9ea8 sp=0x2fe9e94 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2fe9fa4, 0x2fe9f6c, 0x0, 0x0, 0x5, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2fe9f48 sp=0x2fe9ea8 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x2d48508) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x2fe9fe4 sp=0x2fe9f48 pc=0x47408c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.newConn.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x2fe9fec sp=0x2fe9fe4 pc=0x473c80 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2fe9fec sp=0x2fe9fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by nhooyr.io/websocket.newConn in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 84 gp=0x2c85c28 m=nil [runnable]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f7c8, 0x2f282b0, 0xf, 0x6, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x3011ecc sp=0x3011eb8 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chansend(0x2f28280, 0x720dac, 0x1, 0x4a7858) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:259 +0x378 fp=0x3011f04 sp=0x3011ecc pc=0x1ef54 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chansend1(0x2f28280, 0x720dac) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:145 +0x28 fp=0x3011f1c sp=0x3011f04 pc=0x1ebd8 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/player.(*Player).manageLoop(0x2f1ca80) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/player/player.go:116 +0x72c fp=0x3011fe4 sp=0x3011f1c pc=0x4a7858 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/player.NewPlayer.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x28 fp=0x3011fec sp=0x3011fe4 pc=0x4a7040 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x3011fec sp=0x3011fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/player.NewPlayer in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x1e4 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 114 gp=0x2c85d48 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c59c9c sp=0x2c59c88 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2c59dfc, 0x2c59d68, 0x0, 0x0, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2c59d3c sp=0x2c59c9c pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*KeyProvider).recvLoop(0x2e33b30) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:52 +0x118 fp=0x2c59fe4 sp=0x2c59d3c pc=0x49552c Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*KeyProvider).Request.(*KeyProvider).startReceiving.func1.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x28 fp=0x2c59fec sp=0x2c59fe4 pc=0x4960c8 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c59fec sp=0x2c59fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*KeyProvider).Request.(*KeyProvider).startReceiving.func1 in goroutine 86 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x60 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 86 gp=0x2c85e68 m=nil [chan send]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f7c8, 0x2f286b0, 0xf, 0x6, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x312351c sp=0x3123508 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chansend(0x2f28680, 0x3123700, 0x1, 0x574084) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:259 +0x378 fp=0x3123554 sp=0x312351c pc=0x1ef54 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chansend1(0x2f28680, 0x3123700) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:145 +0x28 fp=0x312356c sp=0x3123554 pc=0x1ebd8 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/player.(*Player).SetPrimaryStream(...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/player/player.go:302 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*AppPlayer).loadCurrentTrack(0x2c27d60, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:228 +0x578 fp=0x3123770 sp=0x312356c pc=0x574084 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*AppPlayer).advanceNext(0x2c27d60, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:519 +0x44c fp=0x3123860 sp=0x3123770 pc=0x57694c Nov 28 23:10:54 volumio go-librespot[1356]: main.(*AppPlayer).handlePlayerEvent(0x2c27d60, 0x3123a54) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:100 +0x364 fp=0x31238fc sp=0x3123860 pc=0x5730f8 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*AppPlayer).Run(0x2c27d60, 0x2f286c0) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:453 +0x5a4 fp=0x3123fe0 sp=0x31238fc pc=0x57e2f8 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*App).withAppPlayer.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x30 fp=0x3123fec sp=0x3123fe0 pc=0x57944c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x3123fec sp=0x3123fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by main.(*App).withAppPlayer in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x348 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 87 gp=0x2c03208 m=nil [chan receive]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f7c8, 0x2c94130, 0xe, 0x7, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5df48 sp=0x2d5df34 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv(0x2c94100, 0x2d5dfd0, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x2d5df84 sp=0x2d5df48 pc=0x1fdc4 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv2(0x2c94100, 0x2d5dfd0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x2d5df98 sp=0x2d5df84 pc=0x1f908 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*App).withAppPlayer.func1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:245 +0x54 fp=0x2d5dfec sp=0x2d5df98 pc=0x57937c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5dfec sp=0x2d5dfec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by main.(*App).withAppPlayer in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:242 +0x3d4 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 88 gp=0x2c03328 m=nil [chan receive]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f7c8, 0x2c940b0, 0xe, 0x7, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c3f73c sp=0x2c3f728 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv(0x2c94080, 0x2c3f7e0, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x2c3f778 sp=0x2c3f73c pc=0x1fdc4 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv2(0x2c94080, 0x2c3f7e0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x20 fp=0x2c3f78c sp=0x2c3f778 pc=0x1f908 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*App).withAppPlayer.func2() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:261 +0x5c fp=0x2c3f7ec sp=0x2c3f78c pc=0x578f90 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c3f7ec sp=0x2c3f7ec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by main.(*App).withAppPlayer in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:258 +0x45c Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 89 gp=0x2c038c8 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609ed98, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c3fde8 sp=0x2c3fdd4 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609ed88, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2c3fe00 sp=0x2c3fde8 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609ed88, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2c3fe14 sp=0x2c3fe00 pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2c27c88, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2c3fe28 sp=0x2c3fe14 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Accept(0x2c27c70) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x294 fp=0x2c3fe70 sp=0x2c3fe28 pc=0x10c974 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).accept(0x2c27c70) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x20 fp=0x2c3fed8 sp=0x2c3fe70 pc=0x2a2504 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPListener).accept(0x2e330b0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x20 fp=0x2c3fef0 sp=0x2c3fed8 pc=0x2ba604 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPListener).Accept(0x2e330b0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0x2c3ff0c sp=0x2c3fef0 pc=0x2b9670 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*onceCloseListener).Accept(0x31042c0) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x34 fp=0x2c3ff24 sp=0x2c3ff0c pc=0x45e914 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Server).Serve(0x2ca9868, {0x72527c, 0x2e330b0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x314 fp=0x2c3ffbc sp=0x2c3ff24 pc=0x43cfd0 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.Serve(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/zeroconf.(*Zeroconf).Serve.func2() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x8c fp=0x2c3ffec sp=0x2c3ffbc pc=0x528d7c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c3ffec sp=0x2c3ffec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x160 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 24 gp=0x304cd88 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609e898, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c58ad4 sp=0x2c58ac0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609e888, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2c58aec sp=0x2c58ad4 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609e888, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2c58b00 sp=0x2c58aec pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2f6aba8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2c58b14 sp=0x2c58b00 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2f6ab90, {0x2efd000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2c58b5c sp=0x2c58b14 pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2f6ab90, {0x2efd000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2c58b88 sp=0x2c58b5c pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x2ca4000, {0x2efd000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2c58bb4 sp=0x2c58b88 pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2ca4000, {0x2efd000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2c58bd4 sp=0x2c58bb4 pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2e3e190, {0x2efd000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x2c58c00 sp=0x2c58bd4 pc=0x386018 Nov 28 23:10:54 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x3198ccc, {0x723a98, 0x2e3e190}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x2c58c3c sp=0x2c58c00 pc=0x136d6c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x3198b48, {0x722604, 0x2ca4000}, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x2c58c64 sp=0x2c58c3c pc=0x386274 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x3198b48, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x2c58dc8 sp=0x2c58c64 pc=0x383974 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x3198b48, {0x311b000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2c58df8 sp=0x2c58dc8 pc=0x3897e4 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).Read(0x319fe00, {0x2d18324, 0x9, 0x9}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x214 fp=0x2c58e1c sp=0x2c58df8 pc=0x15ab44 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadAtLeast({0x7227f8, 0x319fe00}, {0x2d18324, 0x9, 0x9}, 0x9) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0x2c58e48 sp=0x2c58e1c pc=0x1020b0 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadFull(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.http2readFrameHeader({0x2d18324, 0x9, 0x9}, {0x7227f8, 0x319fe00}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x54 fp=0x2c58e70 sp=0x2c58e48 pc=0x3f30fc Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2Framer).ReadFrame(0x2d18300) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x88 fp=0x2c58eec sp=0x2c58e70 pc=0x3f3894 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2clientConnReadLoop).run(0x2c58fdc) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x150 fp=0x2c58fa4 sp=0x2c58eec pc=0x4180b0 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2ClientConn).readLoop(0x2d16408) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x68 fp=0x2c58fe4 sp=0x2c58fa4 pc=0x4175a4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*http2Transport).newClientConn.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x28 fp=0x2c58fec sp=0x2c58fe4 pc=0x4105f0 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c58fec sp=0x2c58fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*http2Transport).newClientConn in goroutine 23 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xcb0 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 47 gp=0x312f208 m=nil [IO wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609e938, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e448a4 sp=0x2e44890 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609e928, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e448bc sp=0x2e448a4 pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609e928, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e448d0 sp=0x2e448bc pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2d38298, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e448e4 sp=0x2e448d0 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2d38280, {0x30d5000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2e4492c sp=0x2e448e4 pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2d38280, {0x30d5000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2e44958 sp=0x2e4492c pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x2fcc148, {0x30d5000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2e44984 sp=0x2e44958 pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2fcc148, {0x30d5000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2e449a4 sp=0x2e44984 pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: io.(*multiReader).Read(0x2fc8380, {0x30d5000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/multi.go:26 +0xb4 fp=0x2e449d0 sp=0x2e449a4 pc=0x103318 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).fill(0x2fca270) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x2e449f4 sp=0x2e449d0 pc=0x15a4b8 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).ReadByte(0x2fca270) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x28 fp=0x2e44a00 sp=0x2e449f4 pc=0x15ad3c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.readFrameHeader(0x2fca270, {0x2df62b8, 0x8, 0x8}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2e44a40 sp=0x2e44a00 pc=0x4771e0 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x2df6288, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2e44b00 sp=0x2e44a40 pc=0x479e44 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).readLoop(0x2df6288, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2e44bc4 sp=0x2e44b00 pc=0x47992c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).reader(0x2df6288, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x2e44c50 sp=0x2e44bc4 pc=0x47ab40 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).Reader(...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).Read(0x2df6288, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x2e44c78 sp=0x2e44c50 pc=0x479210 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*ApiServer).serve.func14({0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:450 +0x22c fp=0x2e44cd0 sp=0x2e44c78 pc=0x570c88 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.HandlerFunc.ServeHTTP(0x2c2e2d8, {0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x2e44ce0 sp=0x2e44cd0 pc=0x4395b4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*ServeMux).ServeHTTP(0x2dc0480, {0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2683 +0x208 fp=0x2e44d1c sp=0x2e44ce0 pc=0x43b414 Nov 28 23:10:54 volumio go-librespot[1356]: main.(*ApiServer).serve.(*ApiServer).allowOriginMiddleware.func15({0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:273 +0xa4 fp=0x2e44d40 sp=0x2e44d1c pc=0x570a44 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.HandlerFunc.ServeHTTP(0x2c0e490, {0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x34 fp=0x2e44d50 sp=0x2e44d40 pc=0x4395b4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.serverHandler.ServeHTTP({0x2d84aa8}, {0x7253b0, 0x2d101e8}, 0x2d10148) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3137 +0xe0 fp=0x2e44d6c sp=0x2e44d50 pc=0x43cba4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*conn).serve(0x2fac000, {0x7256a8, 0x2da2270}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2039 +0x61c fp=0x2e44fdc sp=0x2e44d6c pc=0x437df4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Server).Serve.gowrap3() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x38 fp=0x2e44fec sp=0x2e44fdc pc=0x43d448 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e44fec sp=0x2e44fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*Server).Serve in goroutine 19 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x468 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 49 gp=0x312f328 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2d5cea8 sp=0x2d5ce94 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2d5cfa4, 0x2d5cf6c, 0x0, 0x0, 0x5, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2d5cf48 sp=0x2d5cea8 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x2df6288) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x2d5cfe4 sp=0x2d5cf48 pc=0x47408c Nov 28 23:10:54 volumio go-librespot[1356]: nhooyr.io/websocket.newConn.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x2d5cfec sp=0x2d5cfe4 pc=0x473c80 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2d5cfec sp=0x2d5cfec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by nhooyr.io/websocket.newConn in goroutine 47 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 102 gp=0x304d208 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e45eb0 sp=0x2e45e9c pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2e45fac, 0x2e45f78, 0x0, 0x0, 0x2, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2e45f50 sp=0x2e45eb0 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).writeLoop(0x30c8168) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2444 +0xd0 fp=0x2e45fe4 sp=0x2e45f50 pc=0x4539dc Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).dialConn.gowrap3() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x28 fp=0x2e45fec sp=0x2e45fe4 pc=0x4507e8 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e45fec sp=0x2e45fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*Transport).dialConn in goroutine 27 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x1444 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 94 gp=0x31946c8 m=nil [chan receive]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f7c8, 0x2d0ecb0, 0xe, 0x7, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e94b64 sp=0x2e94b50 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv(0x2d0ec80, 0x2e94ca4, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x4b0 fp=0x2e94ba0 sp=0x2e94b64 pc=0x1fdc4 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.chanrecv1(0x2d0ec80, 0x2e94ca4) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:442 +0x20 fp=0x2e94bb4 sp=0x2e94ba0 pc=0x1f8e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).addTLS(0x30c8218, {0x725688, 0xad3b20}, {0x2e6a020, 0x18}, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1579 +0x308 fp=0x2e94cb0 sp=0x2e94bb4 pc=0x44e704 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).dialConn(0xa67ab0, {0x725688, 0xad3b20}, {{}, 0x0, {0x30c22c0, 0x5}, {0x2e6a020, 0x1c}, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1658 +0x8b0 fp=0x2e94f48 sp=0x2e94cb0 pc=0x44f340 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).dialConnFor(0xa67ab0, 0x3138060) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1485 +0x84 fp=0x2e94fe0 sp=0x2e94f48 pc=0x44de50 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).queueForDial.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1449 +0x30 fp=0x2e94fec sp=0x2e94fe0 pc=0x44dda0 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e94fec sp=0x2e94fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*Transport).queueForDial in goroutine 128 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1449 +0x98 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 121 gp=0x31947e8 m=nil [runnable]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f928, 0x7609e758, 0x2, 0x2, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e40afc sp=0x2e40ae8 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.netpollblock(0x7609e748, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0x100 fp=0x2e40b14 sp=0x2e40afc pc=0x540f0 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.runtime_pollWait(0x7609e748, 0x72) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x54 fp=0x2e40b28 sp=0x2e40b14 pc=0x8eba8 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).wait(0x2cca1f8, 0x72, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2e40b3c sp=0x2e40b28 pc=0x108108 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*pollDesc).waitRead(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Nov 28 23:10:54 volumio go-librespot[1356]: internal/poll.(*FD).Read(0x2cca1e0, {0x3090000, 0xa000, 0xa000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2e40b84 sp=0x2e40b3c pc=0x1092f4 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*netFD).Read(0x2cca1e0, {0x3090000, 0xa000, 0xa000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x38 fp=0x2e40bb0 sp=0x2e40b84 pc=0x2a0610 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*conn).Read(0x2eb84e0, {0x3090000, 0xa000, 0xa000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x48 fp=0x2e40bdc sp=0x2e40bb0 pc=0x2b07f0 Nov 28 23:10:54 volumio go-librespot[1356]: net.(*TCPConn).Read(0x2eb84e0, {0x3090000, 0xa000, 0xa000}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x44 fp=0x2e40bfc sp=0x2e40bdc pc=0x2c3a44 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*atLeastReader).Read(0x2e6e010, {0x3090000, 0xa000, 0xa000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x78 fp=0x2e40c28 sp=0x2e40bfc pc=0x386018 Nov 28 23:10:54 volumio go-librespot[1356]: bytes.(*Buffer).ReadFrom(0x2ef2ccc, {0x723a98, 0x2e6e010}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0xa4 fp=0x2e40c64 sp=0x2e40c28 pc=0x136d6c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readFromUntil(0x2ef2b48, {0x722604, 0x2eb84e0}, 0x5) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xd4 fp=0x2e40c8c sp=0x2e40c64 pc=0x386274 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2ef2b48, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x134 fp=0x2e40df0 sp=0x2e40c8c pc=0x383974 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2ef2b48, {0x2e68000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2e40e20 sp=0x2e40df0 pc=0x3897e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).Read(0x30c80b8, {0x2e68000, 0x1000, 0x1000}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1977 +0x16c fp=0x2e40e54 sp=0x2e40e20 pc=0x45138c Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).fill(0x2d3a960) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x10c fp=0x2e40e78 sp=0x2e40e54 pc=0x15a4b8 Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).Peek(0x2d3a960, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:148 +0x68 fp=0x2e40e84 sp=0x2e40e78 pc=0x15a63c Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).readLoop(0x30c80b8) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2141 +0x194 fp=0x2e40fe4 sp=0x2e40e84 pc=0x451f1c Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).dialConn.gowrap2() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x28 fp=0x2e40fec sp=0x2e40fe4 pc=0x45083c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e40fec sp=0x2e40fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*Transport).dialConn in goroutine 103 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1799 +0x13f4 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 122 gp=0x3194908 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2c57eb0 sp=0x2c57e9c pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2c57fac, 0x2c57f78, 0x0, 0x0, 0x2, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2c57f50 sp=0x2c57eb0 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).writeLoop(0x30c80b8) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2444 +0xd0 fp=0x2c57fe4 sp=0x2c57f50 pc=0x4539dc Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).dialConn.gowrap3() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x28 fp=0x2c57fec sp=0x2c57fe4 pc=0x4507e8 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2c57fec sp=0x2c57fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*Transport).dialConn in goroutine 103 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1800 +0x1444 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 226 gp=0x305a488 m=nil [runnable]: Nov 28 23:10:54 volumio go-librespot[1356]: crypto/internal/bigmod.(*Nat).maybeSubtractModulus(0x2e11754, 0x0, 0x2fe41c0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/bigmod/nat.go:522 +0x178 fp=0x2e10cec sp=0x2e10cec pc=0x325c80 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/internal/bigmod.(*Nat).montgomeryMul(0x2e11754, 0x2e11754, 0x2e11754, 0x2fe41c0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/bigmod/nat.go:697 +0x5a8 fp=0x2e113f0 sp=0x2e10cec pc=0x3265c0 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/internal/bigmod.(*Nat).ExpShortVarTime(0x2e11754, 0x2e11760, 0x10001, 0x2fe41c0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/internal/bigmod/nat.go:793 +0x250 fp=0x2e11520 sp=0x2e113f0 pc=0x327b90 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/rsa.encrypt(0x30c0b18, {0x2e2caa9, 0x100, 0x157}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/rsa/rsa.go:495 +0x104 fp=0x2e1176c sp=0x2e11520 pc=0x34e368 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/rsa.VerifyPKCS1v15(0x30c0b18, 0x5, {0x2e62160, 0x20, 0x20}, {0x2e2caa9, 0x100, 0x157}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/rsa/pkcs1v15.go:354 +0x1dc fp=0x2e117ac sp=0x2e1176c pc=0x34b6a0 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.checkSignature(0x4, {0x2e2c6e1, 0x3b4, 0x51f}, {0x2e2caa9, 0x100, 0x157}, {0x5ef488, 0x30c0b18}, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/x509.go:930 +0x2bc fp=0x2e11820 sp=0x2e117ac pc=0x372e6c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).CheckSignatureFrom(0x2d2e848, 0x30d1348) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/x509.go:850 +0x100 fp=0x2e11854 sp=0x2e11820 pc=0x372a0c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).buildChains.func1(0x2, {0x30d1348, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/verify.go:915 +0x16c fp=0x2e118cc sp=0x2e11854 pc=0x3709ac Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).buildChains(0x2d2e848, {0x2eb8018, 0x2, 0x2}, 0x2f2a578, 0x2e11ae8) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/verify.go:953 +0xfc fp=0x2e11938 sp=0x2e118cc pc=0x3706fc Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).buildChains.func1(0x1, {0x2d2e848, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/verify.go:947 +0x530 fp=0x2e119b0 sp=0x2e11938 pc=0x370d70 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).buildChains(0x2cd62c8, {0x2ca43e8, 0x1, 0x1}, 0x2f2a578, 0x3014ae8) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/verify.go:956 +0x170 fp=0x2e11a1c sp=0x2e119b0 pc=0x370770 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/x509.(*Certificate).Verify(0x2cd62c8, {{0x2e6a020, 0x18}, 0x2ec09d8, 0x2d08540, {0xc1ca54f7679207bc, 0x3c359d56d, 0xaa8e80}, {0x0, 0x0, ...}, ...}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/x509/verify.go:806 +0x38c fp=0x2e11ae0 sp=0x2e11a1c pc=0x36fe7c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).verifyServerCertificate(0x2ef2fc8, {0x2ec09c0, 0x2, 0x2}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client.go:997 +0x6d0 fp=0x2e11c60 sp=0x2e11ae0 pc=0x391568 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*clientHandshakeStateTLS13).readServerCertificate(0x2e11dfc) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client_tls13.go:531 +0x2a0 fp=0x2e11d68 sp=0x2e11c60 pc=0x3951e8 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*clientHandshakeStateTLS13).handshake(0x2e11dfc) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client_tls13.go:96 +0x2fc fp=0x2e11d8c sp=0x2e11d68 pc=0x392244 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).clientHandshake(0x2ef2fc8, {0x7256c8, 0x2d3a6f0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/handshake_client.go:263 +0x530 fp=0x2e11ea0 sp=0x2e11d8c pc=0x38c958 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).clientHandshake-fm({0x7256c8, 0x2d3a6f0}) Nov 28 23:10:54 volumio go-librespot[1356]: :1 +0x38 fp=0x2e11eb8 sp=0x2e11ea0 pc=0x3c4438 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).handshakeContext(0x2ef2fc8, {0x725688, 0xad3b20}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1553 +0x338 fp=0x2e11fb0 sp=0x2e11eb8 pc=0x38a30c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).HandshakeContext(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1493 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).addTLS.func2() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1573 +0x78 fp=0x2e11fec sp=0x2e11fb0 pc=0x44e9a8 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e11fec sp=0x2e11fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by net/http.(*persistConn).addTLS in goroutine 94 Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1569 +0x2e4 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 128 gp=0x2ce2368 m=nil [select]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f96c, 0x0, 0x9, 0x3, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e93870 sp=0x2e9385c pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.selectgo(0x2e939c4, 0x2e93938, 0x0, 0x0, 0x6, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0xaf0 fp=0x2e93910 sp=0x2e93870 pc=0x705e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).roundTrip(0x30c80b8, 0x2d02820) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2675 +0x87c fp=0x2e93a5c sp=0x2e93910 pc=0x454950 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).roundTrip(0xa67ab0, 0x2d10008) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:608 +0x858 fp=0x2e93b78 sp=0x2e93a5c pc=0x4494f0 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Transport).RoundTrip(0xa67ab0, 0x2d10008) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/roundtrip.go:17 +0x24 fp=0x2e93b90 sp=0x2e93b78 pc=0x42d82c Nov 28 23:10:54 volumio go-librespot[1356]: net/http.send(0x2d10008, {0x72294c, 0xa67ab0}, {0x0, 0x0, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:259 +0x540 fp=0x2e93cbc sp=0x2e93b90 pc=0x3e8554 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Client).send(0x2f88d40, 0x2d10008, {0x0, 0x0, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:180 +0x98 fp=0x2e93d00 sp=0x2e93cbc pc=0x3e7e48 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Client).do(0x2f88d40, 0x2d10008) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:724 +0x8bc fp=0x2e93e10 sp=0x2e93d00 pc=0x3ea248 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*Client).Do(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:590 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).downloadChunk.func1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:111 +0x290 fp=0x2e93e6c sp=0x2e93e10 pc=0x4924c8 Nov 28 23:10:54 volumio go-librespot[1356]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x2e93f38, {0x724ee8, 0x2cb0060}, 0x0, {0x0, 0x0}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:88 +0xf0 fp=0x2e93eec sp=0x2e93e6c pc=0x496294 Nov 28 23:10:54 volumio go-librespot[1356]: github.com/cenkalti/backoff/v4.RetryNotifyWithData[...](...) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:54 Nov 28 23:10:54 volumio go-librespot[1356]: github.com/cenkalti/backoff/v4.RetryWithData[...](0x2e51f38, {0x724ee8, 0x2cb0060}) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:43 +0x54 fp=0x2e93f18 sp=0x2e93eec pc=0x49617c Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).downloadChunk(0x2d68660, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:110 +0x84 fp=0x2e93f44 sp=0x2e93f18 pc=0x4921f8 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:153 +0xc8 fp=0x2e93fc4 sp=0x2e93f44 pc=0x4926ac Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2e93fe4 sp=0x2e93fc4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2e93fec sp=0x2e93fe4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e93fec sp=0x2e93fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 129 gp=0x2ce2488 m=nil [runnable]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.asyncPreempt2() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt.go:307 +0x38 fp=0x2e97798 sp=0x2e9778c pc=0x5abbc Nov 28 23:10:54 volumio go-librespot[1356]: runtime.asyncPreempt() Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/preempt_arm.s:44 +0x98 fp=0x2e97854 sp=0x2e97798 pc=0x93fb4 Nov 28 23:10:54 volumio go-librespot[1356]: math/bits.Mul64(0x8c99dda4fef3eddf, 0xc915890034f0470) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/math/bits/bits.go:480 +0x28 fp=0x2e97860 sp=0x2e97858 pc=0xc4bf4 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/internal/poly1305.bitsMul64(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/bits_go1.13.go:20 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/internal/poly1305.mul64(0x8c99dda4fef3eddf, 0xc915890034f0470) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:117 +0x38 fp=0x2e97884 sp=0x2e97860 pc=0x377e14 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/internal/poly1305.updateGeneric(0x2e97a14, {0x2f7bf41, 0x4000, 0x40bf}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:197 +0x5e4 fp=0x2e97958 sp=0x2e97884 pc=0x3784f0 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/internal/poly1305.(*macGeneric).Write(0x2e97a14, {0x2f7bf41, 0x4001, 0x40bf}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/sum_generic.go:74 +0x15c fp=0x2e97984 sp=0x2e97958 pc=0x377b00 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/internal/poly1305.(*MAC).Write(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/internal/poly1305/poly1305.go:80 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/chacha20poly1305.writeWithPadding(0x2e97a14, {0x2f7bf41, 0x4001, 0x40bf}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:16 +0x44 fp=0x2e979b4 sp=0x2e97984 pc=0x378bec Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).openGeneric(0x2e623a0, {0x2f7bf41, 0x0, 0x40bf}, {0x313a5a0, 0xc, 0xc}, {0x2f7bf41, 0x4011, 0x40bf}, ...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_generic.go:64 +0x1ac fp=0x2e97b1c sp=0x2e979b4 pc=0x379304 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).open(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305_noasm.go:14 Nov 28 23:10:54 volumio go-librespot[1356]: vendor/golang.org/x/crypto/chacha20poly1305.(*chacha20poly1305).Open(0x2e623a0, {0x2f7bf41, 0x0, 0x40bf}, {0x313a5a0, 0xc, 0xc}, {0x2f7bf41, 0x4011, 0x40bf}, ...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/vendor/golang.org/x/crypto/chacha20poly1305/chacha20poly1305.go:82 +0xc4 fp=0x2e97b68 sp=0x2e97b1c pc=0x378afc Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*xorNonceAEAD).Open(0x313a5a0, {0x2f7bf41, 0x0, 0x40bf}, {0x2ef2e78, 0x8, 0x8}, {0x2f7bf41, 0x4011, 0x40bf}, ...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/cipher_suites.go:519 +0xc0 fp=0x2e97bb4 sp=0x2e97b68 pc=0x37dfa4 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*halfConn).decrypt(0x2ef2e54, {0x2f7bf3c, 0x4016, 0x40c4}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:380 +0x4bc fp=0x2e97c60 sp=0x2e97bb4 pc=0x382678 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecordOrCCS(0x2ef2d88, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:686 +0xbfc fp=0x2e97dc4 sp=0x2e97c60 pc=0x38443c Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).readRecord(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Nov 28 23:10:54 volumio go-librespot[1356]: crypto/tls.(*Conn).Read(0x2ef2d88, {0x3335d20, 0xa2e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x15c fp=0x2e97df4 sp=0x2e97dc4 pc=0x3897e4 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*persistConn).Read(0x30c8168, {0x3335d20, 0xa2e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:1977 +0x16c fp=0x2e97e28 sp=0x2e97df4 pc=0x45138c Nov 28 23:10:54 volumio go-librespot[1356]: bufio.(*Reader).Read(0x2d68b40, {0x3335d20, 0xa2e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:227 +0x12c fp=0x2e97e4c sp=0x2e97e28 pc=0x15aa5c Nov 28 23:10:54 volumio go-librespot[1356]: io.(*LimitedReader).Read(0x2e6e100, {0x3335d20, 0x122e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:479 +0xc4 fp=0x2e97e6c sp=0x2e97e4c pc=0x102878 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*body).readLocked(0x2d3a690, {0x3335d20, 0x122e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:840 +0x4c fp=0x2e97e98 sp=0x2e97e6c pc=0x446748 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*body).Read(0x2d3a690, {0x3335d20, 0x122e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transfer.go:832 +0xe8 fp=0x2e97ecc sp=0x2e97e98 pc=0x446654 Nov 28 23:10:54 volumio go-librespot[1356]: net/http.(*bodyEOFSignal).Read(0x2d3a6c0, {0x3335d20, 0x122e0, 0x122e0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:2833 +0xc0 fp=0x2e97f08 sp=0x2e97ecc pc=0x455570 Nov 28 23:10:54 volumio go-librespot[1356]: io.ReadAll({0x72276c, 0x2d3a6c0}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:712 +0x84 fp=0x2e97f44 sp=0x2e97f08 pc=0x1030e8 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:169 +0x140 fp=0x2e97fc4 sp=0x2e97f44 pc=0x492724 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2e97fe4 sp=0x2e97fc4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2e97fec sp=0x2e97fe4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e97fec sp=0x2e97fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 211 gp=0x2ce26c8 m=nil [sync.Cond.Wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0x2d032f0, 0x14, 0x4, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e536f4 sp=0x2e536e0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:54 volumio go-librespot[1356]: sync.runtime_notifyListWait(0x2d032e8, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x2e53720 sp=0x2e536f4 pc=0x90a94 Nov 28 23:10:54 volumio go-librespot[1356]: sync.(*Cond).Wait(0x2d032e0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x2e53744 sp=0x2e53720 pc=0x9cc44 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x2e537c4 sp=0x2e53744 pc=0x492b94 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2e537e4 sp=0x2e537c4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2e537ec sp=0x2e537e4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e537ec sp=0x2e537ec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 212 gp=0x2ce27e8 m=nil [sync.Cond.Wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0x2d03330, 0x14, 0x4, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e53ef4 sp=0x2e53ee0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:54 volumio go-librespot[1356]: sync.runtime_notifyListWait(0x2d03328, 0x0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x2e53f20 sp=0x2e53ef4 pc=0x90a94 Nov 28 23:10:54 volumio go-librespot[1356]: sync.(*Cond).Wait(0x2d03320) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x2e53f44 sp=0x2e53f20 pc=0x9cc44 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x2e53fc4 sp=0x2e53f44 pc=0x492b94 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2e53fe4 sp=0x2e53fc4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2e53fec sp=0x2e53fe4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e53fec sp=0x2e53fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 214 gp=0x2ce2a28 m=nil [sync.Cond.Wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0x2d032f0, 0x14, 0x4, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2e54ef4 sp=0x2e54ee0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:54 volumio go-librespot[1356]: sync.runtime_notifyListWait(0x2d032e8, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x2e54f20 sp=0x2e54ef4 pc=0x90a94 Nov 28 23:10:54 volumio go-librespot[1356]: sync.(*Cond).Wait(0x2d032e0) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x2e54f44 sp=0x2e54f20 pc=0x9cc44 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x2e54fc4 sp=0x2e54f44 pc=0x492b94 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x2) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2e54fe4 sp=0x2e54fc4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2e54fec sp=0x2e54fe4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2e54fec sp=0x2e54fec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: goroutine 215 gp=0x2ce2b48 m=nil [sync.Cond.Wait]: Nov 28 23:10:54 volumio go-librespot[1356]: runtime.gopark(0x68f938, 0x2d03330, 0x14, 0x4, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0x104 fp=0x2eaf6f4 sp=0x2eaf6e0 pc=0x5c82c Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goparkunlock(...) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Nov 28 23:10:54 volumio go-librespot[1356]: sync.runtime_notifyListWait(0x2d03328, 0x1) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x1e4 fp=0x2eaf720 sp=0x2eaf6f4 pc=0x90a94 Nov 28 23:10:54 volumio go-librespot[1356]: sync.(*Cond).Wait(0x2d03320) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0xbc fp=0x2eaf744 sp=0x2eaf720 pc=0x9cc44 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).fetchChunk(0x2d68660, 0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:139 +0x5b0 fp=0x2eaf7c4 sp=0x2eaf744 pc=0x492b94 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.func1(0x3) Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x24 fp=0x2eaf7e4 sp=0x2eaf7c4 pc=0x492db4 Nov 28 23:10:54 volumio go-librespot[1356]: go-librespot/audio.(*HttpChunkedReader).prefetchChunks.gowrap1() Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x30 fp=0x2eaf7ec sp=0x2eaf7e4 pc=0x492d64 Nov 28 23:10:54 volumio go-librespot[1356]: runtime.goexit({}) Nov 28 23:10:54 volumio go-librespot[1356]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_arm.s:859 +0x4 fp=0x2eaf7ec sp=0x2eaf7ec pc=0x9346c Nov 28 23:10:54 volumio go-librespot[1356]: created by go-librespot/audio.(*HttpChunkedReader).prefetchChunks in goroutine 92 Nov 28 23:10:54 volumio go-librespot[1356]: /home/runner/work/go-librespot/go-librespot/audio/chunked_reader.go:198 +0x34 Nov 28 23:10:54 volumio go-librespot[1356]: Aborted Nov 28 23:10:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Nov 28 23:10:54 volumio ntpd[733]: Soliciting pool server 160.119.193.252 Nov 28 23:10:54 volumio ntpd[733]: Soliciting pool server 102.64.113.151 Nov 28 23:10:54 volumio ntpd[733]: Soliciting pool server 102.64.113.151 Nov 28 23:10:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 28 23:10:55 volumio ntpd[733]: Soliciting pool server 102.64.112.164 Nov 28 23:10:55 volumio ntpd[733]: Soliciting pool server 2001:43f8:d60:300::206 Nov 28 23:10:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 28 23:10:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Nov 28 23:10:58 volumio systemd[1]: Stopped go-librespot Daemon. Nov 28 23:10:58 volumio systemd[1]: Started go-librespot Daemon. Nov 28 23:10:58 volumio go-librespot[1608]: Librespot-go daemon starting... Nov 28 23:11:00 volumio ntpd[733]: receive: Unexpected origin timestamp 0xeaf35ae2.e462a917 does not match aorg 0000000000.00000000 from server@196.10.54.57 xmt 0xeaf35ae3.ff2f689f Nov 28 23:11:00 volumio ntpd[733]: receive: Unexpected origin timestamp 0xeaf35ae2.e456a2d9 does not match aorg 0000000000.00000000 from server@160.119.193.252 xmt 0xeaf35ae4.00474492 Nov 28 23:11:00 volumio ntpd[733]: receive: Unexpected origin timestamp 0xeaf35ae2.e45c06aa does not match aorg 0000000000.00000000 from server@196.49.100.58 xmt 0xeaf35ae3.ffdec1d6 Nov 28 23:11:00 volumio ntpd[733]: receive: Unexpected origin timestamp 0xeaf35ae2.e459b693 does not match aorg 0000000000.00000000 from server@196.10.52.58 xmt 0xeaf35ae4.01913a2f Nov 28 23:11:00 volumio ntpd[733]: receive: Unexpected origin timestamp 0xeaf35ae2.e45e2c34 does not match aorg 0000000000.00000000 from server@196.10.52.57 xmt 0xeaf35ae4.03515f2c Nov 28 23:11:01 volumio go-librespot[1608]: time="2024-11-28T23:11:01+02:00" level=info msg="generated new device id: edeb11dd22a704a7bc316aeb7e122051a5efb71f" Nov 28 23:11:01 volumio go-librespot[1608]: time="2024-11-28T23:11:01+02:00" level=debug msg="stored credentials found for 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:11:04 volumio volumio-remote-updater[543]: [2024-11-28 23:11:04] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="zeroconf server listening on port 45391" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="obtained new client token: AAD+3tl5ohd9DMv6Rutp2P66gYkFe6OHqAdyED6pFRjV2QkmesfIC+jPN/8Muv6zGNyNaDtzmRyKpij9uBRiny+fyQbC+cNqDj0KWo1P1iOr9fzhWEETv3is8UuJlQojmMjh/C2H6XePK51dWR89nDDdHnnkLtJwaRdh/MGclO9NKViG6xVq3Fh1SwgeQ5UuyEkT3/GZ7uzSK3/hEyQ6Gm6GqwH8m12aLCh1C0ii284L4d1yKohDfB45XTxd" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=info msg="connected to ap-gew1.spotify.com:4070" Nov 28 23:11:05 volumio go-librespot[1608]: time="2024-11-28T23:11:05+02:00" level=debug msg="completed keyexchange" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="completed challenge" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="authenticated as 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="authenticated as 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="dealer connection opened" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="initializing zeroconf session, username: 31nohowztxgyhq6i6ub2cqsjj6fu" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="autoplay enabled: false" Nov 28 23:11:06 volumio go-librespot[1608]: time="2024-11-28T23:11:06+02:00" level=debug msg="received connection id: OGRjYjkxYzctMjBhZi00ZjE3LWI0ZjAtNmEwNjFlZjQzOTBmK2RlYWxlcit0Y3A6Ly8wYWNhNDBiYS5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMDhGN0YzQjQzQzJFMkI2MjMzMjBBQjQwRjdGNjY1OTZGQUJEOEJENzE4OTM0MTA0MjdEQ0Q0QjA5RDg1Rjc3Nw==" Nov 28 23:11:06 volumio volumio[931]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 28 23:11:06 volumio volumio[931]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 28 23:11:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:11:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:11:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:11:07 volumio go-librespot[1608]: time="2024-11-28T23:11:07+02:00" level=debug msg="put connect state because NEW_DEVICE" Nov 28 23:11:07 volumio volumio[931]: info: Starting MyVolumio Remote Streaming Endpoints Nov 28 23:11:08 volumio go-librespot[1608]: time="2024-11-28T23:11:08+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 28 23:11:08 volumio go-librespot[1608]: time="2024-11-28T23:11:08+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 336" Nov 28 23:11:08 volumio go-librespot[1608]: time="2024-11-28T23:11:08+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 28 23:11:08 volumio go-librespot[1608]: time="2024-11-28T23:11:08+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2897" Nov 28 23:11:09 volumio volumio[1352]: .......................................................................................++++ Nov 28 23:11:09 volumio volumio[931]: info: MyVolumio login type: Token Nov 28 23:11:09 volumio volumio[931]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 28 23:11:10 volumio volumio-remote-updater[543]: [2024-11-28 23:11:10] [connect] Successful connection Nov 28 23:11:11 volumio volumio[931]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 28 23:11:11 volumio go-librespot[1608]: time="2024-11-28T23:11:11+02:00" level=debug msg="handling transfer player command from 72080b76f79fb9e6073cb87da435b2a743f16990" Nov 28 23:11:11 volumio go-librespot[1608]: time="2024-11-28T23:11:11+02:00" level=debug msg="resolved context of track" uri="spotify:artist:2N72bJ8IYB4KZmKmxz5Xkk" Nov 28 23:11:11 volumio go-librespot[1608]: time="2024-11-28T23:11:11+02:00" level=trace msg="fetched new page 0 with 5 items (list: 5)" uri="spotify:artist:2N72bJ8IYB4KZmKmxz5Xkk" Nov 28 23:11:11 volumio go-librespot[1608]: time="2024-11-28T23:11:11+02:00" level=debug msg="loading track (paused: false, position: 4206ms)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=trace msg="emitting websocket event: will_play" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2838" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="selected format OGG_VORBIS_320 (067ce78b250a7a6de1c9d793b60adccc7fab8007)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="requested aes key for file 067ce78b250a7a6de1c9d793b60adccc7fab8007, gid: 3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1863" Nov 28 23:11:12 volumio go-librespot[1608]: time="2024-11-28T23:11:12+02:00" level=debug msg="fetched first chunk of 20, total size is 10150592 bytes" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=trace msg="seek to 4206ms (diff: 226ms, samples: 185484, bytes: 137513)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+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" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=debug msg="created new output device" Nov 28 23:11:13 volumio go-librespot[1608]: time="2024-11-28T23:11:13+02:00" level=info msg="loaded track \"Fady Shewaya\" (paused: false, position: 4206ms, duration: 231735ms, prefetched: false)" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:13 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=trace msg="scheduling prefetch in 198s" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=trace msg="emitting websocket event: metadata" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=trace msg="emitting websocket event: active" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=debug msg="sending successful reply for dealer request" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 28 23:11:14 volumio go-librespot[1608]: time="2024-11-28T23:11:14+02:00" level=trace msg="emitting websocket event: playing" Nov 28 23:11:20 volumio volumio[931]: info: Starting Streaming Service Transparent Proxy Nov 28 23:11:20 volumio volumio[931]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 28 23:11:20 volumio volumio[931]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 28 23:11:20 volumio volumio[931]: info: Streaming services startup Nov 28 23:11:20 volumio volumio[931]: info: Starting Streaming Daemon Nov 28 23:11:20 volumio volumio[931]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 28 23:11:20 volumio sudo[1896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 28 23:11:20 volumio sudo[1896]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 28 23:11:21 volumio volumio[931]: info: Getting Spotify volume Nov 28 23:11:22 volumio go-librespot[1608]: time="2024-11-28T23:11:22+02:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:3qRGs7H1bPfshHh19syRKQ" Nov 28 23:11:22 volumio volumio[931]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Nov 28 23:11:22 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:11:22 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 28 23:11:22 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 28 23:11:22 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 28 23:11:23 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 28 23:11:23 volumio sudo[1896]: pam_unix(sudo:session): session closed for user root Nov 28 23:11:23 volumio volumio[931]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:03OoXcz5TPOCyU6RTR1bgk","play_origin":"com.spotify.service.freetierartist"}} Nov 28 23:11:23 volumio volumio[931]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:03OoXcz5TPOCyU6RTR1bgk","name":"Dari Ya Alby","artist_names":["Hamza Namira"],"album_name":"Dari Ya Alby","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c2228ce3bb97ef17c8ded7f0","position":587300,"duration":270237,"release_date":"year:2018 month:2 day:8","track_number":1,"disc_number":1}} Nov 28 23:11:23 volumio volumio[931]: SPOTIFY: received: {"type":"active","data":null} Nov 28 23:11:23 volumio volumio[931]: info: Aligning Spotify Volume to Volumio Volume Nov 28 23:11:23 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Nov 28 23:11:23 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Nov 28 23:11:23 volumio volumio[931]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:03OoXcz5TPOCyU6RTR1bgk","play_origin":"com.spotify.service.freetierartist"}} Nov 28 23:11:23 volumio volumio[931]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 23:11:23 volumio volumio[931]: TypeError: Cannot read property 'service' of undefined Nov 28 23:11:23 volumio volumio[931]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Nov 28 23:11:23 volumio volumio[931]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Nov 28 23:11:23 volumio volumio[931]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Nov 28 23:11:23 volumio volumio[931]: at WebSocket.emit (events.js:315:20) Nov 28 23:11:23 volumio volumio[931]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Nov 28 23:11:23 volumio volumio[931]: at Receiver.emit (events.js:315:20) Nov 28 23:11:23 volumio volumio[931]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Nov 28 23:11:23 volumio volumio[931]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Nov 28 23:11:23 volumio volumio[931]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Nov 28 23:11:23 volumio volumio[931]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Nov 28 23:11:23 volumio volumio[931]: at writeOrBuffer (internal/streams/writable.js:358:12) Nov 28 23:11:23 volumio volumio[931]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Nov 28 23:11:23 volumio volumio[931]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Nov 28 23:11:23 volumio volumio[931]: at Socket.emit (events.js:315:20) Nov 28 23:11:23 volumio volumio[931]: at addChunk (internal/streams/readable.js:309:12) Nov 28 23:11:23 volumio volumio[931]: at readableAddChunk (internal/streams/readable.js:284:9) Nov 28 23:11:23 volumio volumio[931]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 28 23:11:23 volumio volumio-remote-updater[543]: [2024-11-28 23:11:23] [connect] Successful connection Nov 28 23:11:23 volumio volumio[1352]: ..................................................++++ Nov 28 23:11:24 volumio volumio[1352]: e is 65537 (0x010001) Nov 28 23:11:24 volumio volumio[1352]: writing RSA key Nov 28 23:11:25 volumio sudo[1939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-28 23:10 Nov 28 23:11:25 volumio sudo[1939]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"