Mar 28 15:29:00 music go-librespot[2138]: time="2026-03-28T15:29:00+01:00" level=trace msg="sent dealer ping" Mar 28 15:29:00 music go-librespot[2138]: time="2026-03-28T15:29:00+01:00" level=trace msg="received dealer pong" Mar 28 15:29:00 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 28 15:29:01 music volumio[1224]: info: Starting Uninstall of plugin music_service - spop Mar 28 15:29:01 music volumio[1224]: info: Uninstalling plugin spop Mar 28 15:29:01 music go-librespot[2138]: time="2026-03-28T15:29:01+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Mar 28 15:29:01 music volumio[1224]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Mar 28 15:29:01 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 15:29:01 music volumio5-onboarding[1480]: time=2026-03-28T15:29:01.928+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:01 music sudo[2261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Mar 28 15:29:01 music sudo[2261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:29:01 music volumio[1224]: info: Disabling plugin spop Mar 28 15:29:01 music volumio5-onboarding[1480]: time=2026-03-28T15:29:01.942+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:01 music volumio[1224]: info: Checking if uninstall.sh is present Mar 28 15:29:01 music volumio[1224]: info: Connection to go-librespot Websocket closed Mar 28 15:29:01 music volumio[1224]: info: Executing uninstall.sh Mar 28 15:29:01 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 15:29:01 music systemd[1]: go-librespot-daemon.service: Killing process 2144 (go-librespot) with signal SIGKILL. Mar 28 15:29:01 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 15:29:01 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:29:01 music volumio[1224]: info: Connection to go-librespot Websocket closed Mar 28 15:29:01 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:01 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:02 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:02 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:02 music sudo[2261]: pam_unix(sudo:session): session closed for user root Mar 28 15:29:02 music sudo[2265]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/uninstall.sh Mar 28 15:29:02 music sudo[2265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:29:02 music sudo[2265]: pam_unix(sudo:session): session closed for user root Mar 28 15:29:02 music volumio[1224]: info: Uninstall script completed Mar 28 15:29:02 music volumio5-onboarding[1480]: time=2026-03-28T15:29:02.106+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:02 music volumio[1224]: info: Removing plugin spop from configuration Mar 28 15:29:02 music volumio[1224]: info: Successfully removed spop configuration files Mar 28 15:29:02 music volumio5-onboarding[1480]: time=2026-03-28T15:29:02.174+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:02 music volumio[1224]: info: Plugin folders cleanup Mar 28 15:29:02 music volumio[1224]: info: Scanning into folder /volumio/app/plugins/ Mar 28 15:29:02 music volumio[1224]: info: Scanning category audio_interface Mar 28 15:29:02 music volumio[1224]: info: Scanning category miscellanea Mar 28 15:29:02 music volumio[1224]: info: Scanning category music_service Mar 28 15:29:02 music volumio[1224]: info: Scanning category plugins.json Mar 28 15:29:02 music volumio[1224]: info: Scanning category system_controller Mar 28 15:29:02 music volumio[1224]: info: Scanning category user_interface Mar 28 15:29:02 music volumio[1224]: info: Scanning into folder /data/plugins/ Mar 28 15:29:02 music volumio[1224]: info: Scanning category music_service Mar 28 15:29:02 music volumio[1224]: info: Cleaning folder for spop Mar 28 15:29:03 music volumio[1224]: info: Scanning category system_controller Mar 28 15:29:03 music volumio[1224]: info: Plugin folders cleanup completed Mar 28 15:29:03 music volumio5-onboarding[1480]: time=2026-03-28T15:29:03.068+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:03 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 15:29:03 music volumio[1224]: info: [{"prettyName":"Sleep Wake Schedule Plugin","name":"SleepWakePlugin","category":"system_controller","version":"2.0.1","icon":"fa-clock-o","isManuallyInstalled":false,"enabled":true,"active":true}] Mar 28 15:29:03 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 15:29:08 music volumio[1224]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 28 15:29:08 music volumio[1224]: info: Received Get System Version Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 15:29:08 music volumio[1224]: info: Received Get System Info Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:29:08 music volumio[1224]: info: Discovery: Getting this device information Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:29:08 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:29:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:29:30 music volumio[1224]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Mar 28 15:29:30 music volumio5-onboarding[1480]: time=2026-03-28T15:29:30.229+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio[1224]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Mar 28 15:29:33 music volumio[1224]: info: Folder /tmp/plugins removed Mar 28 15:29:33 music volumio5-onboarding[1480]: time=2026-03-28T15:29:33.023+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio5-onboarding[1480]: time=2026-03-28T15:29:33.804+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio[1224]: info: Check plugin dependencies Mar 28 15:29:33 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 15:29:33 music volumio5-onboarding[1480]: time=2026-03-28T15:29:33.905+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio[1224]: info: Checking if plugin already exists Mar 28 15:29:33 music volumio5-onboarding[1480]: time=2026-03-28T15:29:33.918+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio[1224]: info: Rename folder Mar 28 15:29:33 music volumio[1224]: info: Folder /tmp/downloaded_plugin.zip removed Mar 28 15:29:33 music volumio5-onboarding[1480]: time=2026-03-28T15:29:33.964+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:33 music volumio[1224]: info: Move to category Mar 28 15:29:35 music volumio5-onboarding[1480]: time=2026-03-28T15:29:35.152+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:35 music volumio[1224]: info: Checking if install.sh is present Mar 28 15:29:35 music volumio[1224]: info: Executing install.sh Mar 28 15:29:35 music sudo[2353]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Mar 28 15:29:35 music sudo[2353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:29:35 music volumio[1224]: info: Installing Go-librespot Mar 28 15:29:35 music volumio5-onboarding[1480]: time=2026-03-28T15:29:35.214+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:35 music volumio[1224]: info: Checking old vollibrespot installs Mar 28 15:29:35 music volumio5-onboarding[1480]: time=2026-03-28T15:29:35.234+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:35 music systemd[1]: Reloading. Mar 28 15:29:36 music volumio[1224]: info: Downloading daemon Mar 28 15:29:36 music volumio5-onboarding[1480]: time=2026-03-28T15:29:36.777+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:39 music volumio[1224]: info: Creating directories Mar 28 15:29:39 music volumio5-onboarding[1480]: time=2026-03-28T15:29:39.556+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:39 music volumio[1224]: info: Creating data directory Mar 28 15:29:39 music volumio5-onboarding[1480]: time=2026-03-28T15:29:39.564+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:39 music volumio[1224]: info: Creating Start Script Mar 28 15:29:39 music volumio5-onboarding[1480]: time=2026-03-28T15:29:39.579+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:39 music systemd[1]: Reloading. Mar 28 15:29:41 music sudo[2353]: pam_unix(sudo:session): session closed for user root Mar 28 15:29:41 music volumio[1224]: Plugin install end detected on script Mar 28 15:29:41 music volumio[1224]: info: Install script completed Mar 28 15:29:41 music volumio5-onboarding[1480]: time=2026-03-28T15:29:41.072+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:41 music volumio[1224]: info: Adding reference to registry Mar 28 15:29:41 music volumio5-onboarding[1480]: time=2026-03-28T15:29:41.083+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 28 15:29:41 music volumio[1224]: info: Done installing plugin. Mar 28 15:29:41 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 15:29:41 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 28 15:29:41 music volumio[1224]: info: Folder /tmp/plugins removed Mar 28 15:29:41 music volumio[1224]: info: Folder /tmp/downloaded_plugin.zip removed Mar 28 15:29:41 music volumio[1224]: info: Folder /data/temp removed Mar 28 15:29:42 music volumio[1224]: info: Enabling plugin spop Mar 28 15:29:42 music volumio[1224]: info: Loading plugin "spop"... Mar 28 15:29:42 music volumio[1224]: info: PLUGIN START: spop Mar 28 15:29:42 music volumio[1224]: info: Creating Spotify config file Mar 28 15:29:42 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 15:29:42 music volumio[1224]: info: Done. Mar 28 15:29:42 music volumio[1224]: info: Spotify config file written Mar 28 15:29:42 music volumio[1224]: info: No need to fix Spotify hosts Mar 28 15:29:42 music sudo[2410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 15:29:42 music sudo[2410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:29:42 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:42 music systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 28 15:29:42 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:29:42 music go-librespot[2412]: go-librespot daemon starting... Mar 28 15:29:42 music sudo[2410]: pam_unix(sudo:session): session closed for user root Mar 28 15:29:42 music go-librespot[2413]: time="2026-03-28T15:29:42+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 15:29:42 music go-librespot[2413]: time="2026-03-28T15:29:42+01:00" level=debug msg="no app state found" Mar 28 15:29:42 music go-librespot[2413]: time="2026-03-28T15:29:42+01:00" level=debug msg="stored credentials not found" Mar 28 15:29:42 music go-librespot[2413]: time="2026-03-28T15:29:42+01:00" level=info msg="generated new device id: 060470522dc4fa6c138e8617448b53ab0d1d362c" Mar 28 15:29:42 music go-librespot[2413]: time="2026-03-28T15:29:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 15:29:43 music go-librespot[2413]: time="2026-03-28T15:29:43+01: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]" Mar 28 15:29:43 music go-librespot[2413]: time="2026-03-28T15:29:43+01: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]" Mar 28 15:29:43 music go-librespot[2413]: time="2026-03-28T15:29:43+01: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]" Mar 28 15:29:43 music go-librespot[2413]: time="2026-03-28T15:29:43+01:00" level=info msg="zeroconf server listening on port 46653" Mar 28 15:29:43 music go-librespot[2413]: time="2026-03-28T15:29:43+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 15:29:45 music volumio[1224]: info: go-librespot daemon successfully initialized Mar 28 15:29:46 music volumio[1224]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 15:29:48 music volumio[1224]: info: Initializing connection to go-librespot Websocket Mar 28 15:29:48 music go-librespot[2413]: time="2026-03-28T15:29:48+01:00" level=debug msg="new websocket client" Mar 28 15:29:48 music volumio[1224]: info: Connection to go-librespot Websocket established Mar 28 15:29:51 music volumio[1224]: info: Getting Spotify volume Mar 28 15:29:51 music volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 28 15:29:51 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:29:51 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:29:51 music volumio[1224]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 15:30:08 music volumio[1224]: verbose: New Socket.io Connection to 192.168.1.116 from 192.168.2.2 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.3 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 7 Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:08 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 15:30:08 music volumio[1224]: info: Received Get System Info Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:30:08 music volumio[1224]: info: Discovery: Getting this device information Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:08 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:08 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:08 music volumio[1224]: info: Listing playlists Mar 28 15:30:08 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 28 15:30:29 music volumio[1224]: info: Received OAUTH Data Mar 28 15:30:29 music volumio[1224]: info: Executing Spotify Oauth Login Mar 28 15:30:29 music volumio[1224]: info: Saving Spotify Refresh Token Mar 28 15:30:30 music volumio[1224]: info: New Spotify access tokenBQD60B-zq5... Mar 28 15:30:30 music volumio[1224]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 15:30:30 music volumio[1224]: SPOTIFY: User informations: {"country":"SK","display_name":"Marek","email":"loganngage@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31gyq4iys47j3hycqrdtfbonwzmy"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31gyq4iys47j3hycqrdtfbonwzmy","id":"31gyq4iys47j3hycqrdtfbonwzmy","images":[],"product":"premium","type":"user","uri":"spotify:user:31gyq4iys47j3hycqrdtfbonwzmy"} Mar 28 15:30:30 music volumio[1224]: info: Creating Spotify config file Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 15:30:30 music volumio[1224]: info: Spotify config file written Mar 28 15:30:30 music sudo[2496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 15:30:30 music sudo[2496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:30:30 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 15:30:30 music systemd[1]: go-librespot-daemon.service: Killing process 2418 (go-librespot) with signal SIGKILL. Mar 28 15:30:30 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 15:30:30 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:30:30 music volumio[1224]: info: Connection to go-librespot Websocket closed Mar 28 15:30:30 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:30:30 music go-librespot[2498]: go-librespot daemon starting... Mar 28 15:30:30 music sudo[2496]: pam_unix(sudo:session): session closed for user root Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=debug msg="app state loaded" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=debug msg="stored credentials not found" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 15:30:30 music sudo[2508]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 28 15:30:30 music sudo[2508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:30:30 music sudo[2508]: pam_unix(sudo:session): session closed for user root Mar 28 15:30:30 music sudo[2510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 28 15:30:30 music sudo[2510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:30:30 music sudo[2510]: pam_unix(sudo:session): session closed for user root Mar 28 15:30:30 music volumio[1224]: info: New Spotify access tokenBQA2CjIMtx... Mar 28 15:30:30 music volumio[1224]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 15:30:30 music volumio[1224]: verbose: New Socket.io Connection to 192.168.1.116 from 192.168.2.1 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.3.1 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 6 Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 15:30:30 music volumio[1224]: SPOTIFY: User informations: {"country":"SK","display_name":"Marek","email":"loganngage@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31gyq4iys47j3hycqrdtfbonwzmy"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31gyq4iys47j3hycqrdtfbonwzmy","id":"31gyq4iys47j3hycqrdtfbonwzmy","images":[],"product":"premium","type":"user","uri":"spotify:user:31gyq4iys47j3hycqrdtfbonwzmy"} Mar 28 15:30:30 music volumio[1224]: info: Spotify Successfully logged in Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 15:30:30 music volumio[1224]: info: [1774708230746] CoreMusicLibrary::Adding element Spotify Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 15:30:30 music volumio[1224]: Cannot find translation for source Spotify Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01: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-gew4.spotify.com:80]" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=info msg="zeroconf server listening on port 40081" Mar 28 15:30:30 music go-librespot[2499]: time="2026-03-28T15:30:30+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:30 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 15:30:30 music volumio[1224]: info: Received Get System Info Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:30:30 music volumio[1224]: info: Discovery: Getting this device information Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:30 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:30 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:30 music volumio[1224]: info: Listing playlists Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 15:30:30 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 15:30:32 music volumio[1224]: info: Received Get System Info Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:30:32 music volumio[1224]: info: Discovery: Getting this device information Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:32 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:30:32 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 28 15:30:33 music volumio[1224]: info: Initializing connection to go-librespot Websocket Mar 28 15:30:33 music go-librespot[2499]: time="2026-03-28T15:30:33+01:00" level=debug msg="new websocket client" Mar 28 15:30:33 music volumio[1224]: info: Connection to go-librespot Websocket established Mar 28 15:30:33 music volumio[1224]: info: go-librespot daemon successfully initialized Mar 28 15:30:34 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 15:30:34 music volumio[1224]: info: Received Get System Info Mar 28 15:30:34 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 15:30:34 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 15:30:34 music volumio[1224]: info: Discovery: Getting this device information Mar 28 15:30:34 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:34 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:34 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 15:30:34 music go-librespot[2499]: time="2026-03-28T15:30:34+01:00" level=debug msg="obtained new client token: AACZ+btEBpgVV9zVOIpOYKdUR/GpKl8A1qpbgSqizXxSySsB7ak4UDA90IomLapm7ZZpbd7zf+rovwqH2oT/21u5cofmPoTGvI2jDLAznIsJCpZ1gDnClF41VR29Ldt9sXq2y2KT+tNiPMvFGQE9jhkCm7zlMiqGs1VPXiTYnC7hXfJohyw8AP0AlutyIKiUnkopWosLsP5nuswu47dfm5sPdKJ4CKgEGhZhXiYMa+YPdQNySyKplqO3dxY=" Mar 28 15:30:34 music go-librespot[2499]: time="2026-03-28T15:30:34+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 15:30:34 music go-librespot[2499]: time="2026-03-28T15:30:34+01:00" level=debug msg="completed keyexchange" Mar 28 15:30:34 music go-librespot[2499]: time="2026-03-28T15:30:34+01:00" level=debug msg="completed challenge" Mar 28 15:30:34 music go-librespot[2499]: time="2026-03-28T15:30:34+01:00" level=info msg="authenticated AP" username="31************************my" Mar 28 15:30:36 music volumio[1224]: info: Getting Spotify volume Mar 28 15:30:36 music volumio[1224]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 28 15:30:36 music volumio[1224]: info: CoreCommandRouter::volumioGetState Mar 28 15:30:36 music volumio[1224]: info: CorePlayQueue::getTrack 0 Mar 28 15:30:36 music volumio[1224]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 15:30:36 music volumio[1224]: info: Initializing connection to go-librespot Websocket Mar 28 15:30:36 music go-librespot[2499]: time="2026-03-28T15:30:36+01:00" level=debug msg="new websocket client" Mar 28 15:30:36 music volumio[1224]: info: Connection to go-librespot Websocket established Mar 28 15:30:36 music volumio[1224]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Mar 28 15:30:36 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Mar 28 15:30:36 music volumio[1224]: info: Creating Spotify config file Mar 28 15:30:36 music volumio[1224]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 15:30:36 music volumio[1224]: info: Spotify config file written Mar 28 15:30:36 music sudo[2529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 15:30:36 music sudo[2529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:30:36 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 15:30:36 music systemd[1]: go-librespot-daemon.service: Killing process 2513 (go-librespot) with signal SIGKILL. Mar 28 15:30:36 music volumio[1224]: info: Connection to go-librespot Websocket closed Mar 28 15:30:36 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 15:30:36 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:30:36 music volumio[1224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 15:30:36 music volumio[1224]: Error: socket hang up Mar 28 15:30:36 music volumio[1224]: at connResetException (node:internal/errors:720:14) Mar 28 15:30:36 music volumio[1224]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 15:30:36 music volumio[1224]: at Socket.emit (node:events:526:35) Mar 28 15:30:36 music volumio[1224]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 15:30:36 music volumio[1224]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 15:30:36 music volumio[1224]: code: 'ECONNRESET', Mar 28 15:30:36 music volumio[1224]: response: undefined Mar 28 15:30:36 music volumio[1224]: } Mar 28 15:30:36 music volumio[1224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 15:30:36 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 15:30:36 music go-librespot[2531]: go-librespot daemon starting... Mar 28 15:30:36 music sudo[2529]: pam_unix(sudo:session): session closed for user root Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01:00" level=debug msg="app state loaded" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01:00" level=debug msg="stored credentials not found" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01: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]" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01: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]" Mar 28 15:30:36 music go-librespot[2542]: time="2026-03-28T15:30:36+01: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]" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=info msg="zeroconf server listening on port 37151" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="obtained new client token: AACwj3JfuEchXIVDQ6oxnP93iqPNJSrzju0ln1imroamRbEw7eZMSoTWL9QsyZdN0qR2RO6aGz/C9RGO+Mqfd4GO9wC1IJlRWvl+6RbjcJBMDAEOvI7iS/RzqNzQ5gB4va2WxbJo1GlAils1AyEIEIaVR0D6RfG5USuD/c1eL+dD1WFMJvcU0+/RuswHtLB7PHKYbIDwmMZJuWp8JWZtEfZFU1EU1L03RqD7mi/iv2D3OPB3eOwpVVT/" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="completed keyexchange" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="completed challenge" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=info msg="authenticated AP" username="31************************my" Mar 28 15:30:37 music sudo[2555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 15:29' Mar 28 15:30:37 music sudo[2555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=info msg="authenticated Login5" username="31************************my" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="stored credentials" username="31************************my" Mar 28 15:30:37 music go-librespot[2542]: time="2026-03-28T15:30:37+01:00" level=debug msg="initializing zeroconf session" username="31************************my" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"