Feb 21 15:06:12 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:06:12 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 21 15:06:30 volumio-pi volumio[1214]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Feb 21 15:06:30 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:30.499+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:32 volumio-pi volumio[1214]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Feb 21 15:06:32 volumio-pi volumio[1214]: info: Folder /tmp/plugins removed Feb 21 15:06:32 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:32.255+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:32 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:32.991+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:32 volumio-pi volumio[1214]: info: Check plugin dependencies Feb 21 15:06:33 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 21 15:06:33 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:33.094+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:33 volumio-pi volumio[1214]: info: Checking if plugin already exists Feb 21 15:06:33 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:33.102+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:33 volumio-pi volumio[1214]: info: Rename folder Feb 21 15:06:33 volumio-pi volumio[1214]: info: Folder /tmp/downloaded_plugin.zip removed Feb 21 15:06:33 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:33.134+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:33 volumio-pi volumio[1214]: info: Move to category Feb 21 15:06:44 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:44.560+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:44 volumio-pi volumio[1214]: info: Checking if install.sh is present Feb 21 15:06:44 volumio-pi volumio[1214]: info: Executing install.sh Feb 21 15:06:44 volumio-pi sudo[3243]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Feb 21 15:06:44 volumio-pi sudo[3243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:06:44 volumio-pi volumio[1214]: info: Installing Go-librespot Feb 21 15:06:44 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:44.711+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:44 volumio-pi volumio[1214]: info: Checking old vollibrespot installs Feb 21 15:06:44 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:44.728+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:44 volumio-pi systemd[1]: Reloading. Feb 21 15:06:46 volumio-pi volumio[1214]: info: Downloading daemon Feb 21 15:06:46 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:46.353+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:48 volumio-pi kernel: usb 1-1.3: USB disconnect, device number 5 Feb 21 15:06:48 volumio-pi thd[713]: Error reading device '/dev/input/event2' Feb 21 15:06:48 volumio-pi thd[713]: Error reading device '/dev/input/event2' Feb 21 15:06:57 volumio-pi volumio[1214]: info: Creating directories Feb 21 15:06:57 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:57.320+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:57 volumio-pi volumio[1214]: info: Creating data directory Feb 21 15:06:57 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:57.332+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:57 volumio-pi volumio[1214]: info: Creating Start Script Feb 21 15:06:57 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:57.348+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:57 volumio-pi systemd[1]: Reloading. Feb 21 15:06:58 volumio-pi sudo[3243]: pam_unix(sudo:session): session closed for user root Feb 21 15:06:58 volumio-pi volumio[1214]: Plugin install end detected on script Feb 21 15:06:58 volumio-pi volumio[1214]: info: Install script completed Feb 21 15:06:58 volumio-pi volumio[1214]: info: Adding reference to registry Feb 21 15:06:58 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:58.890+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:58 volumio-pi volumio5-onboarding[1369]: time=2026-02-21T15:06:58.891+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 21 15:06:58 volumio-pi volumio[1214]: info: Done installing plugin. Feb 21 15:06:58 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 21 15:06:58 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 21 15:06:58 volumio-pi volumio[1214]: info: Folder /tmp/plugins removed Feb 21 15:06:58 volumio-pi volumio[1214]: info: Folder /tmp/downloaded_plugin.zip removed Feb 21 15:06:58 volumio-pi volumio[1214]: info: Folder /data/temp removed Feb 21 15:07:05 volumio-pi volumio[1214]: info: Enabling plugin spop Feb 21 15:07:05 volumio-pi volumio[1214]: info: Loading plugin "spop"... Feb 21 15:07:06 volumio-pi volumio[1214]: info: PLUGIN START: spop Feb 21 15:07:06 volumio-pi volumio[1214]: info: Creating Spotify config file Feb 21 15:07:06 volumio-pi volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 21 15:07:06 volumio-pi volumio[1214]: info: Done. Feb 21 15:07:06 volumio-pi volumio[1214]: info: Spotify config file written Feb 21 15:07:06 volumio-pi volumio[1214]: info: No need to fix Spotify hosts Feb 21 15:07:06 volumio-pi sudo[3345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 21 15:07:06 volumio-pi sudo[3345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 21 15:07:06 volumio-pi 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. Feb 21 15:07:06 volumio-pi 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. Feb 21 15:07:06 volumio-pi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 21 15:07:06 volumio-pi go-librespot[3347]: go-librespot daemon starting... Feb 21 15:07:06 volumio-pi sudo[3345]: pam_unix(sudo:session): session closed for user root Feb 21 15:07:06 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:06+01:00" level=info msg="running go-librespot 0.6.2" Feb 21 15:07:06 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:06+01:00" level=debug msg="no app state found" Feb 21 15:07:06 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:06+01:00" level=debug msg="stored credentials not found" Feb 21 15:07:06 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:06+01:00" level=info msg="generated new device id: 5a355a4e1f682e9ab6db10eac1de65dda4de1681" Feb 21 15:07:06 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 21 15:07:07 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 15:07:07 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 21 15:07:07 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 21 15:07:07 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:07+01:00" level=info msg="zeroconf server listening on port 41375" Feb 21 15:07:09 volumio-pi volumio[1214]: info: go-librespot daemon successfully initialized Feb 21 15:07:12 volumio-pi volumio[1214]: info: Initializing connection to go-librespot Websocket Feb 21 15:07:12 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:12+01:00" level=debug msg="new websocket client" Feb 21 15:07:12 volumio-pi volumio[1214]: info: Connection to go-librespot Websocket established Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="obtained new client token: AAAcFcr1EYR2rYkkpD3ozPTyX2qZVhuxB1+2ZHalNZfV6XoizHgCf3TTW64MyCIS831BlNJaIGZ2vbPNf8cyiyOQVtCF1V75SNYbctqxOQVoAr7KEISS9+69dpy61Fzopm85QGFvgALXzqEPnaYVEjA+T7Lemr3hGuJiJUNN7TwMVkyQ+JqFSCUaEqQdiGKBwZu3YVnOJQ0pg1eCmNYEIT024GJMeBYsnMbJhbs3ybxaxDCFhK6Kuuxznw==" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="completed keyexchange" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="completed challenge" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=info msg="authenticated AP" username="al******84" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=info msg="authenticated Login5" username="al******84" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=info msg="accepted zeroconf from A56 di Alessio" username="al******84" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="dealer connection opened" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=trace msg="starting accesspoint recv loop" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=trace msg="starting dealer recv loop" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=trace msg="received accesspoint ping" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 21 15:07:13 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:13+01:00" level=debug msg="received connection id: YTViOWM3NDEtNDU2...RUVFMUE2Q0I0Nw==" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="received accesspoint pong ack" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="handling transfer player command from 184a78eb59de81f4f6ce09cf42eefa0d62d700ac" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1DWZZbwlv3Vmtr" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="fetched new page 0 with 200 items (list: 200)" uri="spotify:playlist:37i9dQZF1DWZZbwlv3Vmtr" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="shuffled context with seed 12170383372544590312 (len: 200, keep: 142)" uri="spotify:playlist:37i9dQZF1DWZZbwlv3Vmtr" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="loading track (paused: false, position: 2793ms)" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="emitting websocket event: will_play" Feb 21 15:07:14 volumio-pi volumio[1214]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1DWZZbwlv3Vmtr","uri":"spotify:track:3O7bHygR4AijQolwOY2nng","play_origin":"playlist"}} Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1442" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="selected format OGG_VORBIS_320 (482137be66226891b1ac5f2674b200ccfa255b96)" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="requested aes key for file 482137be66226891b1ac5f2674b200ccfa255b96, gid: 3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="fetched first chunk of 9, total size is 4499523 bytes" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="seek to 2793ms (diff: 99ms, samples: 123171, bytes: 76752)" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="created new output device" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=info msg="loaded track \"machine\" (paused: false, position: 2793ms, duration: 128000ms, prefetched: false)" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="scheduling prefetch in 95s" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="emitting websocket event: metadata" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="emitting websocket event: active" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="sending successful reply for dealer request" Feb 21 15:07:14 volumio-pi volumio[1214]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3O7bHygR4AijQolwOY2nng","name":"machine","artist_names":["aroramo"],"album_name":"machine","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a74467d449ce26d86daa1db1","position":2793,"duration":128000,"release_date":"year:2024 month:12 day:8","track_number":1,"disc_number":1}} Feb 21 15:07:14 volumio-pi volumio[1214]: SPOTIFY: received: {"type":"active","data":null} Feb 21 15:07:14 volumio-pi volumio[1214]: info: Aligning Spotify Volume to Volumio Volume Feb 21 15:07:14 volumio-pi volumio[1214]: info: CoreCommandRouter::volumioGetState Feb 21 15:07:14 volumio-pi volumio[1214]: info: CorePlayQueue::getTrack 0 Feb 21 15:07:14 volumio-pi volumio[1214]: info: Setting Spotify Volume from Volumio: 86 Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=trace msg="emitting websocket event: playing" Feb 21 15:07:14 volumio-pi volumio[1214]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1DWZZbwlv3Vmtr","uri":"spotify:track:3O7bHygR4AijQolwOY2nng","resume":false,"play_origin":"playlist"}} Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="fetched chunk 3/8, size: 524288" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi volumio[1214]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:07:14 volumio-pi volumio[1214]: TypeError: Cannot read properties of undefined (reading 'service') Feb 21 15:07:14 volumio-pi volumio[1214]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 21 15:07:14 volumio-pi volumio[1214]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Feb 21 15:07:14 volumio-pi volumio[1214]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 21 15:07:14 volumio-pi volumio[1214]: at WebSocket.emit (node:events:514:28) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver.emit (node:events:514:28) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 21 15:07:14 volumio-pi volumio[1214]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 21 15:07:14 volumio-pi volumio[1214]: at writeOrBuffer (node:internal/streams/writable:399:12) Feb 21 15:07:14 volumio-pi volumio[1214]: at _write (node:internal/streams/writable:340:10) Feb 21 15:07:14 volumio-pi volumio[1214]: at Writable.write (node:internal/streams/writable:344:10) Feb 21 15:07:14 volumio-pi volumio[1214]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 21 15:07:14 volumio-pi volumio[1214]: at Socket.emit (node:events:514:28) Feb 21 15:07:14 volumio-pi volumio[1214]: at addChunk (node:internal/streams/readable:343:12) Feb 21 15:07:14 volumio-pi volumio[1214]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="fetched chunk 2/8, size: 524288" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:14 volumio-pi go-librespot[3348]: time="2026-02-21T15:07:14+01:00" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:3O7bHygR4AijQolwOY2nng" Feb 21 15:07:15 volumio-pi sudo[3403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-21 15:06' Feb 21 15:07:15 volumio-pi sudo[3403]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"