Jan 10 16:30:01 volumio go-librespot[1557]: time="2026-01-10T16:30:01+07:00" level=trace msg="received accesspoint ping" Jan 10 16:30:01 volumio go-librespot[1557]: time="2026-01-10T16:30:01+07:00" level=trace msg="received accesspoint pong ack" Jan 10 16:30:02 volumio go-librespot[1557]: time="2026-01-10T16:30:02+07:00" level=trace msg="sent dealer ping" Jan 10 16:30:02 volumio go-librespot[1557]: time="2026-01-10T16:30:02+07:00" level=trace msg="received dealer pong" Jan 10 16:30:03 volumio go-librespot[1557]: time="2026-01-10T16:30:03+07:00" level=debug msg="handling pause player command from 4a3ef8580e9795d81b833c7b1a8e23e1e819eb37" Jan 10 16:30:03 volumio go-librespot[1557]: time="2026-01-10T16:30:03+07:00" level=warning msg="failed handling dealer request" error="no primary stream" Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: multiroom , disableAudioOutput Jan 10 16:30:10 volumio volumio[1314]: info: MRS: Starting browser stream Jan 10 16:30:10 volumio volumio[1314]: info: MRS: Setting this device as single Jan 10 16:30:10 volumio volumio[1314]: info: Jan 10 16:30:10 volumio volumio[1314]: [1768037410076] ---------------------------- Setting Multiroom Single Jan 10 16:30:10 volumio volumio[1314]: info: MRS: disable multiroom output Jan 10 16:30:10 volumio volumio[1314]: info: MRS: Set multiroom target PCM to volumioDiscard Jan 10 16:30:10 volumio volumio[1314]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioDiscard Jan 10 16:30:10 volumio volumio[1314]: verbose: New Socket.io Connection to 192.168.100.11 from 192.168.100.14 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: Received Get System Info Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:30:10 volumio volumio[1314]: info: Discovery: Getting this device information Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetVisibleSources Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 10 16:30:10 volumio volumio[1314]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 10 16:30:10 volumio volumio[1314]: info: Received Get System Info Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:30:10 volumio volumio[1314]: info: Discovery: Getting this device information Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:10 volumio volumio[1314]: info: Listing playlists Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::volumioGetQueue Jan 10 16:30:10 volumio volumio[1314]: info: CoreStateMachine::getQueue Jan 10 16:30:10 volumio volumio[1314]: info: CorePlayQueue::getQueue Jan 10 16:30:10 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 10 16:30:10 volumio volumio[1314]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Jan 10 16:30:10 volumio volumio[1314]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioLocalPlayback Jan 10 16:30:10 volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Jan 10 16:30:11 volumio volumio[1314]: info: MRS: STOPPING volumioStreaming Jan 10 16:30:11 volumio sudo[5511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Jan 10 16:30:11 volumio sudo[5511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:30:11 volumio sudo[5513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/stream.m3u8 /tmp/hls/stream19.ts /tmp/hls/stream20.ts /tmp/hls/stream21.ts /tmp/hls/stream22.ts Jan 10 16:30:11 volumio sudo[5513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:30:11 volumio sudo[5513]: pam_unix(sudo:session): session closed for user root Jan 10 16:30:11 volumio volumio[1314]: info: MRS: Removed streaming files Jan 10 16:30:11 volumio systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Jan 10 16:30:11 volumio systemd[1]: volumioStreaming.service: Killing process 5468 (ffmpeg) with signal SIGKILL. Jan 10 16:30:11 volumio systemd[1]: volumioStreaming.service: Killing process 5469 (ffmpeg) with signal SIGKILL. Jan 10 16:30:11 volumio systemd[1]: volumioStreaming.service: Killing process 5471 (ffmpeg) with signal SIGKILL. Jan 10 16:30:11 volumio systemd[1]: volumioStreaming.service: Deactivated successfully. Jan 10 16:30:11 volumio systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Jan 10 16:30:11 volumio systemd[1]: volumioStreaming.service: Consumed 2.208s CPU time. Jan 10 16:30:11 volumio sudo[5511]: pam_unix(sudo:session): session closed for user root Jan 10 16:30:11 volumio volumio[1314]: info: MRS: volumioStreaming STOPPED Jan 10 16:30:20 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 10 16:30:24 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:24 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:26 volumio volumio[1314]: info: Executing endpoint metavolumio Jan 10 16:30:26 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 16:30:26 volumio volumio[1314]: info: Executing endpoint metavolumio Jan 10 16:30:26 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 16:30:26 volumio volumio[1314]: info: Executing endpoint metavolumio Jan 10 16:30:26 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 16:30:32 volumio go-librespot[1557]: time="2026-01-10T16:30:32+07:00" level=trace msg="sent dealer ping" Jan 10 16:30:32 volumio go-librespot[1557]: time="2026-01-10T16:30:32+07:00" level=trace msg="received dealer pong" Jan 10 16:30:33 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 16:30:33 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 16:30:39 volumio volumio[1314]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 16:30:51 volumio volumio[1314]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 10 16:30:51 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 10 16:30:51 volumio volumio[1314]: info: Creating Spotify config file Jan 10 16:30:51 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 16:30:51 volumio volumio[1314]: info: Spotify config file written Jan 10 16:30:51 volumio sudo[5586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 10 16:30:51 volumio sudo[5586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:30:51 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 10 16:30:51 volumio systemd[1]: go-librespot-daemon.service: Killing process 1559 (go-librespot) with signal SIGKILL. Jan 10 16:30:51 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 10 16:30:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:30:51 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.618s CPU time. Jan 10 16:30:51 volumio volumio[1314]: info: Connection to go-librespot Websocket closed Jan 10 16:30:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:30:51 volumio go-librespot[5588]: go-librespot daemon starting... Jan 10 16:30:51 volumio sudo[5586]: pam_unix(sudo:session): session closed for user root Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=info msg="running go-librespot 0.6.2" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=debug msg="app state loaded" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 10 16:30:51 volumio go-librespot[5589]: time="2026-01-10T16:30:51+07:00" level=info msg="zeroconf server listening on port 34355" Jan 10 16:30:52 volumio go-librespot[5589]: time="2026-01-10T16:30:52+07:00" level=debug msg="obtained new client token: AAD5n2cLW/2Bk4cHI47bAozB2m0gqQkEWGyW1/2ofkUiRDrBpvH7aCyYSYUvzd7A0HqYVFiJjGBi1LKu5VbteUytiuHdpyL5Ed0lBvsB01drWYUZYhAcJOAvls2kHjBEhj0hkDjCzq/zqFgb4r2Eod5uGwIgXNShEsPQ7gg9+e9dxhxzz0WmZGgWs/+TmOWoAFT/d5k9AA5/K3s/E+VpaxpwTkxJjWSIqT8xBt8qe8tDGSzyyIPOTnA=" Jan 10 16:30:52 volumio go-librespot[5589]: time="2026-01-10T16:30:52+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 10 16:30:52 volumio go-librespot[5589]: time="2026-01-10T16:30:52+07:00" level=debug msg="completed keyexchange" Jan 10 16:30:52 volumio go-librespot[5589]: time="2026-01-10T16:30:52+07:00" level=debug msg="completed challenge" Jan 10 16:30:53 volumio go-librespot[5589]: time="2026-01-10T16:30:53+07:00" level=info msg="authenticated AP" username="31************************xa" Jan 10 16:30:53 volumio go-librespot[5589]: time="2026-01-10T16:30:53+07:00" level=info msg="authenticated Login5" username="31************************xa" Jan 10 16:30:53 volumio go-librespot[5589]: time="2026-01-10T16:30:53+07:00" level=debug msg="initializing zeroconf session" username="31************************xa" Jan 10 16:30:54 volumio volumio[1314]: info: Initializing connection to go-librespot Websocket Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="new websocket client" Jan 10 16:30:54 volumio volumio[1314]: info: Connection to go-librespot Websocket established Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="dealer connection opened" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=trace msg="starting accesspoint recv loop" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=trace msg="starting dealer recv loop" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=trace msg="received accesspoint ping" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 10 16:30:54 volumio go-librespot[5589]: time="2026-01-10T16:30:54+07:00" level=debug msg="received connection id: Y2MwOGE2NzgtYjFm...Rjc2QzUwMEM0Nw==" Jan 10 16:30:54 volumio volumio[1314]: info: go-librespot daemon successfully initialized Jan 10 16:30:55 volumio go-librespot[5589]: time="2026-01-10T16:30:55+07:00" level=debug msg="put connect state because NEW_DEVICE" Jan 10 16:30:55 volumio go-librespot[5589]: time="2026-01-10T16:30:55+07:00" level=trace msg="received accesspoint pong ack" Jan 10 16:30:57 volumio volumio[1314]: info: Getting Spotify volume Jan 10 16:30:57 volumio volumio[1314]: info: Spotify volume: 100 Jan 10 16:30:57 volumio volumio[1314]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 10 16:30:57 volumio volumio[1314]: info: Initializing connection to go-librespot Websocket Jan 10 16:30:57 volumio go-librespot[5589]: time="2026-01-10T16:30:57+07:00" level=debug msg="new websocket client" Jan 10 16:30:57 volumio volumio[1314]: info: Connection to go-librespot Websocket established Jan 10 16:30:57 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:30:57 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:30:57 volumio volumio[1314]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Jan 10 16:30:57 volumio volumio[1314]: SPOTIFY: SPOTIFY VOLUME 100 Jan 10 16:30:57 volumio volumio[1314]: SPOTIFY: VOLUMIO VOLUME 78 Jan 10 16:30:57 volumio volumio[1314]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 10 16:30:57 volumio volumio[1314]: info: Setting Spotify Volume from Volumio: 78 Jan 10 16:30:57 volumio volumio[1314]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 10 16:30:57 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 10 16:30:57 volumio volumio[1314]: info: Creating Spotify config file Jan 10 16:30:57 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 16:30:57 volumio volumio[1314]: info: Spotify config file written Jan 10 16:30:57 volumio sudo[5616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 10 16:30:57 volumio sudo[5616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:30:57 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 10 16:30:57 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 10 16:30:57 volumio volumio[1314]: info: Connection to go-librespot Websocket closed Jan 10 16:30:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:30:57 volumio volumio[1314]: info: Connection to go-librespot Websocket closed Jan 10 16:30:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:30:57 volumio go-librespot[5618]: go-librespot daemon starting... Jan 10 16:30:57 volumio sudo[5616]: pam_unix(sudo:session): session closed for user root Jan 10 16:30:57 volumio go-librespot[5619]: time="2026-01-10T16:30:57+07:00" level=info msg="running go-librespot 0.6.2" Jan 10 16:30:57 volumio go-librespot[5619]: time="2026-01-10T16:30:57+07:00" level=debug msg="app state loaded" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=info msg="zeroconf server listening on port 45457" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="obtained new client token: AABSeXR0YQcb6GZrNFMUw95YdM8OauaPQtKjzYuFloh3+myXg8c0fU2sYQWEbpvqpcMVh1NSdnhI8uGDtxyw5RbdaEY1TP/UkuCvYEVAs38NlIrt+rzyD8TIprAlNhOho8l86rDJZVKERGygkV9coLSdAi6xaxy+u/lRIe8cLTxXLhp1AcVorTNCnQJZl5oXwO+x1shXvT+MPftqYfO1XEKXHVXC6gQW86HUdScPGNZwNrBY0Z8wOBBOFQ==" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="completed keyexchange" Jan 10 16:30:58 volumio go-librespot[5619]: time="2026-01-10T16:30:58+07:00" level=debug msg="completed challenge" Jan 10 16:30:59 volumio go-librespot[5619]: time="2026-01-10T16:30:59+07:00" level=info msg="authenticated AP" username="31************************xa" Jan 10 16:30:59 volumio volumio[1314]: SPOTIFY: SETTING SPOTIFY VOLUME 78 Jan 10 16:30:59 volumio volumio[1314]: info: Sending Spotify command with payload to local API: /player/volume Jan 10 16:30:59 volumio go-librespot[5619]: time="2026-01-10T16:30:59+07:00" level=info msg="authenticated Login5" username="31************************xa" Jan 10 16:30:59 volumio go-librespot[5619]: time="2026-01-10T16:30:59+07:00" level=debug msg="initializing zeroconf session" username="31************************xa" Jan 10 16:31:00 volumio volumio[1314]: info: Getting Spotify volume Jan 10 16:31:00 volumio volumio[1314]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 10 16:31:00 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState Jan 10 16:31:00 volumio volumio[1314]: info: CorePlayQueue::getTrack 0 Jan 10 16:31:00 volumio volumio[1314]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Jan 10 16:31:00 volumio volumio[1314]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 10 16:31:00 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 10 16:31:00 volumio volumio[1314]: info: Creating Spotify config file Jan 10 16:31:00 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 16:31:00 volumio volumio[1314]: info: Spotify config file written Jan 10 16:31:00 volumio sudo[5630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 10 16:31:00 volumio sudo[5630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:31:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 10 16:31:00 volumio systemd[1]: go-librespot-daemon.service: Killing process 5621 (go-librespot) with signal SIGKILL. Jan 10 16:31:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 10 16:31:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:31:00 volumio volumio[1314]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 16:31:00 volumio volumio[1314]: Error: socket hang up Jan 10 16:31:00 volumio volumio[1314]: at connResetException (node:internal/errors:720:14) Jan 10 16:31:00 volumio volumio[1314]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 10 16:31:00 volumio volumio[1314]: at Socket.emit (node:events:526:35) Jan 10 16:31:00 volumio volumio[1314]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 10 16:31:00 volumio volumio[1314]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 10 16:31:00 volumio volumio[1314]: code: 'ECONNRESET', Jan 10 16:31:00 volumio volumio[1314]: response: undefined Jan 10 16:31:00 volumio volumio[1314]: } Jan 10 16:31:00 volumio volumio[1314]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 16:31:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:31:00 volumio go-librespot[5632]: go-librespot daemon starting... Jan 10 16:31:00 volumio sudo[5630]: pam_unix(sudo:session): session closed for user root Jan 10 16:31:00 volumio go-librespot[5644]: time="2026-01-10T16:31:00+07:00" level=info msg="running go-librespot 0.6.2" Jan 10 16:31:00 volumio go-librespot[5644]: time="2026-01-10T16:31:00+07:00" level=debug msg="app state loaded" Jan 10 16:31:00 volumio go-librespot[5644]: time="2026-01-10T16:31:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 16:31:01 volumio go-librespot[5644]: time="2026-01-10T16:31:01+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 10 16:31:01 volumio go-librespot[5644]: time="2026-01-10T16:31:01+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 10 16:31:01 volumio go-librespot[5644]: time="2026-01-10T16:31:01+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 10 16:31:01 volumio go-librespot[5644]: time="2026-01-10T16:31:01+07:00" level=info msg="zeroconf server listening on port 40865" Jan 10 16:31:01 volumio go-librespot[5644]: time="2026-01-10T16:31:01+07:00" level=debug msg="obtained new client token: AACLdZBrhXr2nJ8zrglxqLcmqYCiOifYkFYKtZs8VYoGv2nCb1E0oxEOKmXmKuXY9likZMtKVlmOkB2sYPXn5W+Li87HnvRosqqaABdRy52Ygv9wgQoF+/2UIWDmnPocumT1FttHGRsJeXxGI83VZDzutFHJMRZ5ADzXiBZpQD9DaQ4VFQ5spy48Jdgiin/j9cg6vUocz4yGOnrdBuO5QORAPZ6Or5IrjbQBl5dvSAnmC3jk2weh/ig=" Jan 10 16:31:01 volumio sudo[5657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-10 16:30' Jan 10 16:31:01 volumio sudo[5657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"